Closed liaohongqing-A closed 4 months ago
medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6/stderr for cassandra03 [root@cassandra03 medusa-job-031155ab-16b7-4075-9d74-89d7dd1a4e1a]# cat stderr [2023-03-17 11:56:23,563] DEBUG: Loading configuration from /etc/medusa/medusa.ini [2023-03-17 11:56:23,564] INFO: Resolving ip address [2023-03-17 11:56:23,565] INFO: ip address to resolve 192.168.83.114 [2023-03-17 11:56:23,565] DEBUG: Resolved 192.168.83.114 to cassandra03 [2023-03-17 11:56:23,566] INFO: Registered backup id 202222222 [2023-03-17 11:56:23,566] INFO: Monitoring provider is noop [2023-03-17 11:56:23,566] DEBUG: Starting backup preparations with Mode: full [2023-03-17 11:56:23,566] DEBUG: Loading storage_provider: local [2023-03-17 11:56:23,574] DEBUG: This server has systemd: True [2023-03-17 11:56:23,741] DEBUG: Blob cassandra03/202222222/meta/schema.cql was not found in cache. [2023-03-17 11:56:23,742] DEBUG: [Storage] Getting object cassandra03/202222222/meta/schema.cql [2023-03-17 11:56:23,742] INFO: Starting backup using Stagger: None Mode: full Name: 202222222 [2023-03-17 11:56:23,742] INFO: Updated from existing status: -1 to new status: 0 for backup id: 202222222 [2023-03-17 11:56:23,742] DEBUG: Process psutil.Process(pid=5643, name='medusa', status='running', started='11:56:21') was set to use only idle IO and CPU resources [2023-03-17 11:56:23,742] INFO: Saving tokenmap and schema [2023-03-17 11:56:23,748] DEBUG: Connecting to cluster, contact points: ['192.168.83.114']; protocol version: 66 [2023-03-17 11:56:23,749] DEBUG: Host 192.168.83.114:9042 is now marked up [2023-03-17 11:56:23,751] DEBUG: [control connection] Opening new connection to 192.168.83.114:9042 [2023-03-17 11:56:23,753] DEBUG: Sending initial options message for new connection (139884584037624) to 192.168.83.114:9042 [2023-03-17 11:56:23,759] DEBUG: Defuncting connection (139884584037624) to 192.168.83.114:9042: <Error from server: code=000a [Protocol error] message="Invalid or unsupported protocol version (66); supported versions are (3/v3, 4/v4, 5/v5-beta)"> [2023-03-17 11:56:23,759] DEBUG: Closing connection (139884584037624) to 192.168.83.114:9042 [2023-03-17 11:56:23,760] DEBUG: Closed socket to 192.168.83.114:9042 [2023-03-17 11:56:23,760] DEBUG: Exception in read for <GeventConnection(139884584037624) 192.168.83.114:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 11:56:23,760] WARNING: Downgrading core protocol version from 66 to 65 for 192.168.83.114:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 11:56:23,761] DEBUG: Sending initial options message for new connection (139884572955592) to 192.168.83.114:9042 [2023-03-17 11:56:23,761] DEBUG: Defuncting connection (139884572955592) to 192.168.83.114:9042: <Error from server: code=000a [Protocol error] message="Invalid or unsupported protocol version (65); supported versions are (3/v3, 4/v4, 5/v5-beta)"> [2023-03-17 11:56:23,761] DEBUG: Closing connection (139884572955592) to 192.168.83.114:9042 [2023-03-17 11:56:23,762] DEBUG: Closed socket to 192.168.83.114:9042 [2023-03-17 11:56:23,762] DEBUG: Exception in read for <GeventConnection(139884572955592) 192.168.83.114:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 11:56:23,762] WARNING: Downgrading core protocol version from 65 to 5 for 192.168.83.114:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 11:56:23,762] DEBUG: Sending initial options message for new connection (139884572954696) to 192.168.83.114:9042 [2023-03-17 11:56:23,763] ERROR: Closing connection <GeventConnection(139884572954696) 192.168.83.114:9042> due to protocol error: Error from server: code=000a [Protocol error] message="Beta version of the protocol used (5/v5-beta), but USE_BETA flag is unset" [2023-03-17 11:56:23,763] DEBUG: Defuncting connection (139884572954696) to 192.168.83.114:9042: <Error from server: code=000a [Protocol error] message="Beta version of the protocol used (5/v5-beta), but USE_BETA flag is unset"> [2023-03-17 11:56:23,763] DEBUG: Closing connection (139884572954696) to 192.168.83.114:9042 [2023-03-17 11:56:23,763] DEBUG: Closed socket to 192.168.83.114:9042 [2023-03-17 11:56:23,763] DEBUG: Exception in read for <GeventConnection(139884572954696) 192.168.83.114:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 11:56:23,764] WARNING: Downgrading core protocol version from 5 to 4 for 192.168.83.114:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 11:56:23,764] DEBUG: Sending initial options message for new connection (139884572956432) to 192.168.83.114:9042 [2023-03-17 11:56:23,765] DEBUG: Received options response on new connection (139884572956432) from 192.168.83.114:9042 [2023-03-17 11:56:23,765] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 11:56:23,765] DEBUG: Sending StartupMessage on <GeventConnection(139884572956432) 192.168.83.114:9042> [2023-03-17 11:56:23,766] DEBUG: Sent StartupMessage on <GeventConnection(139884572956432) 192.168.83.114:9042> [2023-03-17 11:56:23,766] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 11:56:23,767] DEBUG: Got ReadyMessage on new connection (139884572956432) from 192.168.83.114:9042 [2023-03-17 11:56:23,767] DEBUG: [control connection] Established new connection <GeventConnection(139884572956432) 192.168.83.114:9042>, registering watchers and refreshing schema and topology [2023-03-17 11:56:23,774] DEBUG: [control connection] Refreshing node list and token map using preloaded results [2023-03-17 11:56:23,774] INFO: Using datacenter 'datacenter1' for DCAwareRoundRobinPolicy (via host '192.168.83.114:9042'); if incorrect, please specify a local_dc to the constructor, or limit contact points to local cluster nodes [2023-03-17 11:56:23,775] DEBUG: [control connection] Found new host to connect to: 192.168.11.103:9042 [2023-03-17 11:56:23,775] INFO: New Cassandra host <Host: 192.168.11.103:9042 datacenter1> discovered [2023-03-17 11:56:23,775] DEBUG: Handling new host <Host: 192.168.11.103:9042 datacenter1> and notifying listeners [2023-03-17 11:56:23,775] DEBUG: Done preparing queries for new host <Host: 192.168.11.103:9042 datacenter1> [2023-03-17 11:56:23,775] DEBUG: Host 192.168.11.103:9042 is now marked up [2023-03-17 11:56:23,775] DEBUG: [control connection] Found new host to connect to: 192.168.11.101:9042 [2023-03-17 11:56:23,776] INFO: New Cassandra host <Host: 192.168.11.101:9042 datacenter1> discovered [2023-03-17 11:56:23,776] DEBUG: Handling new host <Host: 192.168.11.101:9042 datacenter1> and notifying listeners [2023-03-17 11:56:23,776] DEBUG: Done preparing queries for new host <Host: 192.168.11.101:9042 datacenter1> [2023-03-17 11:56:23,776] DEBUG: Host 192.168.11.101:9042 is now marked up [2023-03-17 11:56:23,776] DEBUG: [control connection] Finished fetching ring info [2023-03-17 11:56:23,776] DEBUG: [control connection] Rebuilding token map due to topology changes [2023-03-17 11:56:23,873] DEBUG: Control connection created [2023-03-17 11:56:23,873] DEBUG: Initializing connection for host 192.168.83.114:9042 [2023-03-17 11:56:23,874] DEBUG: Initializing connection for host 192.168.11.103:9042 [2023-03-17 11:56:23,875] DEBUG: Sending initial options message for new connection (139884584035944) to 192.168.83.114:9042 [2023-03-17 11:56:23,875] DEBUG: Sending initial options message for new connection (139884564098184) to 192.168.11.103:9042 [2023-03-17 11:56:23,875] DEBUG: Received options response on new connection (139884584035944) from 192.168.83.114:9042 [2023-03-17 11:56:23,876] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 11:56:23,876] DEBUG: Sending StartupMessage on <GeventConnection(139884584035944) 192.168.83.114:9042> [2023-03-17 11:56:23,876] DEBUG: Sent StartupMessage on <GeventConnection(139884584035944) 192.168.83.114:9042> [2023-03-17 11:56:23,876] DEBUG: Received options response on new connection (139884564098184) from 192.168.11.103:9042 [2023-03-17 11:56:23,876] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 11:56:23,876] DEBUG: Sending StartupMessage on <GeventConnection(139884564098184) 192.168.11.103:9042> [2023-03-17 11:56:23,876] DEBUG: Sent StartupMessage on <GeventConnection(139884564098184) 192.168.11.103:9042> [2023-03-17 11:56:23,877] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 11:56:23,877] DEBUG: Got ReadyMessage on new connection (139884584035944) from 192.168.83.114:9042 [2023-03-17 11:56:23,877] DEBUG: Finished initializing connection for host 192.168.83.114:9042 [2023-03-17 11:56:23,877] DEBUG: Added pool for host 192.168.83.114:9042 to session [2023-03-17 11:56:23,877] DEBUG: Not starting MonitorReporter thread for Insights; not supported by server version 3.11.13 on ControlConnection host 192.168.83.114:9042 [2023-03-17 11:56:23,877] DEBUG: Started Session with client_id f1bb7e52-09c3-42a5-8035-cecf9dc16947 and session_id e9fcb686-0ef8-4fa9-a073-43809515e47b [2023-03-17 11:56:23,916] DEBUG: Checking placement using dc and rack... [2023-03-17 11:56:23,916] DEBUG: Initializing connection for host 192.168.11.101:9042 [2023-03-17 11:56:23,916] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 11:56:23,917] DEBUG: Got ReadyMessage on new connection (139884564098184) from 192.168.11.103:9042 [2023-03-17 11:56:23,917] DEBUG: Finished initializing connection for host 192.168.11.103:9042 [2023-03-17 11:56:23,917] DEBUG: Added pool for host 192.168.11.103:9042 to session [2023-03-17 11:56:23,917] INFO: Resolving ip address 192.168.83.114 [2023-03-17 11:56:23,917] INFO: ip address to resolve 192.168.83.114 [2023-03-17 11:56:23,918] DEBUG: Resolved 192.168.83.114 to cassandra03 [2023-03-17 11:56:23,918] DEBUG: Checking host 192.168.83.114 against 192.168.83.114/cassandra03 [2023-03-17 11:56:23,918] INFO: Resolving ip address 192.168.11.101 [2023-03-17 11:56:23,918] INFO: ip address to resolve 192.168.11.101 [2023-03-17 11:56:23,919] DEBUG: Sending initial options message for new connection (139884564090608) to 192.168.11.101:9042 [2023-03-17 11:56:23,919] DEBUG: Resolved 192.168.11.101 to cassandra02 [2023-03-17 11:56:23,919] INFO: Resolving ip address 192.168.11.103 [2023-03-17 11:56:23,919] INFO: ip address to resolve 192.168.11.103 [2023-03-17 11:56:23,919] DEBUG: Resolved 192.168.11.103 to cassandra01 [2023-03-17 11:56:23,919] INFO: Resolving ip address 192.168.83.114 [2023-03-17 11:56:23,919] INFO: ip address to resolve 192.168.83.114 [2023-03-17 11:56:23,920] DEBUG: Received options response on new connection (139884564090608) from 192.168.11.101:9042 [2023-03-17 11:56:23,920] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 11:56:23,920] DEBUG: Sending StartupMessage on <GeventConnection(139884564090608) 192.168.11.101:9042> [2023-03-17 11:56:23,920] DEBUG: Sent StartupMessage on <GeventConnection(139884564090608) 192.168.11.101:9042> [2023-03-17 11:56:23,920] DEBUG: Resolved 192.168.83.114 to cassandra03 [2023-03-17 11:56:23,920] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 11:56:23,921] DEBUG: Got ReadyMessage on new connection (139884564090608) from 192.168.11.101:9042 [2023-03-17 11:56:23,921] DEBUG: Finished initializing connection for host 192.168.11.101:9042 [2023-03-17 11:56:23,921] DEBUG: Added pool for host 192.168.11.101:9042 to session [2023-03-17 11:56:23,921] DEBUG: Closing connection (139884584035944) to 192.168.83.114:9042 [2023-03-17 11:56:23,921] DEBUG: Closed socket to 192.168.83.114:9042 [2023-03-17 11:56:23,921] DEBUG: Closing connection (139884564098184) to 192.168.11.103:9042 [2023-03-17 11:56:23,921] DEBUG: Closed socket to 192.168.11.103:9042 [2023-03-17 11:56:23,921] DEBUG: Closing connection (139884564090608) to 192.168.11.101:9042 [2023-03-17 11:56:23,922] DEBUG: Closed socket to 192.168.11.101:9042 [2023-03-17 11:56:23,922] DEBUG: Shutting down Cluster Scheduler [2023-03-17 11:56:23,922] DEBUG: Shutting down control connection [2023-03-17 11:56:23,922] DEBUG: Closing connection (139884572956432) to 192.168.83.114:9042 [2023-03-17 11:56:23,922] DEBUG: Closed socket to 192.168.83.114:9042 [2023-03-17 11:56:23,929] DEBUG: Blob cassandra03/202222222/meta/tokenmap.json was not found in cache. [2023-03-17 11:56:23,929] DEBUG: [Storage] Getting object cassandra03/202222222/meta/tokenmap.json [2023-03-17 11:56:23,929] DEBUG: [Storage] Reading blob cassandra03/202222222/meta/tokenmap.json... [2023-03-17 11:56:23,929] DEBUG: [Storage] Reading blob cassandra03/202222222/meta/tokenmap.json... [2023-03-17 11:56:23,929] DEBUG: [Storage] Getting object cassandra03/202222222/meta/schema.cql [2023-03-17 11:56:23,929] DEBUG: [Storage] Reading blob cassandra03/202222222/meta/schema.cql... [2023-03-17 11:56:23,929] DEBUG: [Storage] Reading blob cassandra03/202222222/meta/schema.cql... [2023-03-17 11:56:23,936] DEBUG: Blob cassandra03/202222222/meta/schema.cql was not found in cache. [2023-03-17 11:56:23,936] DEBUG: [Storage] Getting object cassandra03/202222222/meta/schema.cql [2023-03-17 11:56:23,937] DEBUG: [Storage] Getting object index/latest_backup/cassandra03/backup_name.txt [2023-03-17 11:56:23,937] DEBUG: [Storage] Getting object cassandra03/None/meta/differential [2023-03-17 11:56:23,937] DEBUG: [Storage] Getting object cassandra03/None/meta/incremental [2023-03-17 11:56:23,937] INFO: Node cassandra03 does not have latest backup [2023-03-17 11:56:23,937] INFO: Creating snapshot [2023-03-17 11:56:23,937] DEBUG: Executing: nodetool -Dcom.sun.jndi.rmiURLParsing=legacy -u cassandra -pw cassandra snapshot -t medusa-202222222 error: Snapshot medusa-202222222 already exists. -- StackTrace -- java.io.IOException: Snapshot medusa-202222222 already exists. at org.apache.cassandra.service.StorageService.takeSnapshot(StorageService.java:3327) at org.apache.cassandra.service.StorageService.takeSnapshot(StorageService.java:3241) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:72) at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:276) at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:112) at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:46) at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237) at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138) at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819) at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801) at javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1468) at javax.management.remote.rmi.RMIConnectionImpl.access$300(RMIConnectionImpl.java:76) at javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1309) at javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1401) at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:829) at sun.reflect.GeneratedMethodAccessor7.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357) at sun.rmi.transport.Transport$1.run(Transport.java:200) at sun.rmi.transport.Transport$1.run(Transport.java:197) at java.security.AccessController.doPrivileged(Native Method) at sun.rmi.transport.Transport.serviceCall(Transport.java:196) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:573) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:834) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:688) at java.security.AccessController.doPrivileged(Native Method) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:687) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:750)
[2023-03-17 11:56:24,664] ERROR: Issue occurred inside handle_backup Name: 202222222 Error: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-202222222']' returned non-zero exit status 2. [2023-03-17 11:56:24,664] INFO: Updated from existing status: 0 to new status: 2 for backup id: 202222222 [2023-03-17 11:56:24,664] ERROR: Error occurred during backup: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-202222222']' returned non-zero exit status 2. Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 197, in handle_backup enable_md5_checks_flag, backup_name, config, monitoring) File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 250, in start_backup cassandra, node_backup, storage, differential_mode, enable_md5, config, backup_name) File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 294, in do_backup with cassandra.create_snapshot(backup_name) as snapshot: File "/usr/local/lib/python3.6/site-packages/medusa/cassandra_utils.py", line 449, in create_snapshot self.snapshot_service.create_snapshot(tag=tag) File "/usr/local/lib/python3.6/site-packages/medusa/service/snapshot/nodetool_snapshot_service.py", line 32, in create_snapshot subprocess.check_call(cmd, stdout=subprocess.DEVNULL, universal_newlines=True) File "/usr/local/lib64/python3.6/site-packages/gevent/subprocess.py", line 350, in check_call raise CalledProcessError(retcode, cmd) # pylint:disable=undefined-variable subprocess.CalledProcessError: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-202222222']' returned non-zero exit status 2. [root@cassandra03 medusa-job-031155ab-16b7-4075-9d74-89d7dd1a4e1a]#
medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6/stderr for cassandra02 [root@cassandra02 medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6]# cat stderr [2023-03-17 14:33:35,700] DEBUG: Loading configuration from /etc/medusa/medusa.ini [2023-03-17 14:33:35,701] INFO: Resolving ip address [2023-03-17 14:33:35,701] INFO: ip address to resolve 192.168.11.101 [2023-03-17 14:33:35,701] DEBUG: Resolved 192.168.11.101 to cassandra02 [2023-03-17 14:33:35,702] INFO: Registered backup id 20230317011 [2023-03-17 14:33:35,702] INFO: Monitoring provider is noop [2023-03-17 14:33:35,702] DEBUG: Starting backup preparations with Mode: full [2023-03-17 14:33:35,702] DEBUG: Loading storage_provider: local [2023-03-17 14:33:35,712] DEBUG: This server has systemd: True [2023-03-17 14:33:35,883] DEBUG: Blob cassandra02/20230317011/meta/schema.cql was not found in cache. [2023-03-17 14:33:35,883] DEBUG: [Storage] Getting object cassandra02/20230317011/meta/schema.cql [2023-03-17 14:33:35,885] INFO: Starting backup using Stagger: None Mode: full Name: 20230317011 [2023-03-17 14:33:35,886] INFO: Updated from existing status: -1 to new status: 0 for backup id: 20230317011 [2023-03-17 14:33:35,886] DEBUG: Process psutil.Process(pid=20751, name='medusa', status='running', started='14:33:34') was set to use only idle IO and CPU resources [2023-03-17 14:33:35,886] INFO: Saving tokenmap and schema [2023-03-17 14:33:35,887] DEBUG: Connecting to cluster, contact points: ['192.168.11.101']; protocol version: 66 [2023-03-17 14:33:35,887] DEBUG: Host 192.168.11.101:9042 is now marked up [2023-03-17 14:33:35,888] DEBUG: [control connection] Opening new connection to 192.168.11.101:9042 [2023-03-17 14:33:35,889] DEBUG: Sending initial options message for new connection (140167826247016) to 192.168.11.101:9042 [2023-03-17 14:33:35,890] DEBUG: Defuncting connection (140167826247016) to 192.168.11.101:9042: <Error from server: code=000a [Protocol error] message="Invalid or unsupported protocol version (66); supported versions are (3/v3, 4/v4, 5/v5-beta)"> [2023-03-17 14:33:35,890] DEBUG: Closing connection (140167826247016) to 192.168.11.101:9042 [2023-03-17 14:33:35,890] DEBUG: Closed socket to 192.168.11.101:9042 [2023-03-17 14:33:35,890] DEBUG: Exception in read for <GeventConnection(140167826247016) 192.168.11.101:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 14:33:35,890] WARNING: Downgrading core protocol version from 66 to 65 for 192.168.11.101:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 14:33:35,891] DEBUG: Sending initial options message for new connection (140167815164928) to 192.168.11.101:9042 [2023-03-17 14:33:35,891] DEBUG: Defuncting connection (140167815164928) to 192.168.11.101:9042: <Error from server: code=000a [Protocol error] message="Invalid or unsupported protocol version (65); supported versions are (3/v3, 4/v4, 5/v5-beta)"> [2023-03-17 14:33:35,891] DEBUG: Closing connection (140167815164928) to 192.168.11.101:9042 [2023-03-17 14:33:35,891] DEBUG: Closed socket to 192.168.11.101:9042 [2023-03-17 14:33:35,891] DEBUG: Exception in read for <GeventConnection(140167815164928) 192.168.11.101:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 14:33:35,892] WARNING: Downgrading core protocol version from 65 to 5 for 192.168.11.101:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 14:33:35,892] DEBUG: Sending initial options message for new connection (140167815164032) to 192.168.11.101:9042 [2023-03-17 14:33:35,893] ERROR: Closing connection <GeventConnection(140167815164032) 192.168.11.101:9042> due to protocol error: Error from server: code=000a [Protocol error] message="Beta version of the protocol used (5/v5-beta), but USE_BETA flag is unset" [2023-03-17 14:33:35,893] DEBUG: Defuncting connection (140167815164032) to 192.168.11.101:9042: <Error from server: code=000a [Protocol error] message="Beta version of the protocol used (5/v5-beta), but USE_BETA flag is unset"> [2023-03-17 14:33:35,893] DEBUG: Closing connection (140167815164032) to 192.168.11.101:9042 [2023-03-17 14:33:35,893] DEBUG: Closed socket to 192.168.11.101:9042 [2023-03-17 14:33:35,893] DEBUG: Exception in read for <GeventConnection(140167815164032) 192.168.11.101:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 14:33:35,893] WARNING: Downgrading core protocol version from 5 to 4 for 192.168.11.101:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 14:33:35,893] DEBUG: Sending initial options message for new connection (140167815166048) to 192.168.11.101:9042 [2023-03-17 14:33:35,894] DEBUG: Received options response on new connection (140167815166048) from 192.168.11.101:9042 [2023-03-17 14:33:35,894] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 14:33:35,894] DEBUG: Sending StartupMessage on <GeventConnection(140167815166048) 192.168.11.101:9042> [2023-03-17 14:33:35,895] DEBUG: Sent StartupMessage on <GeventConnection(140167815166048) 192.168.11.101:9042> [2023-03-17 14:33:35,895] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 14:33:35,895] DEBUG: Got ReadyMessage on new connection (140167815166048) from 192.168.11.101:9042 [2023-03-17 14:33:35,895] DEBUG: [control connection] Established new connection <GeventConnection(140167815166048) 192.168.11.101:9042>, registering watchers and refreshing schema and topology [2023-03-17 14:33:35,901] DEBUG: [control connection] Refreshing node list and token map using preloaded results [2023-03-17 14:33:35,901] INFO: Using datacenter 'datacenter1' for DCAwareRoundRobinPolicy (via host '192.168.11.101:9042'); if incorrect, please specify a local_dc to the constructor, or limit contact points to local cluster nodes [2023-03-17 14:33:35,901] DEBUG: [control connection] Found new host to connect to: 192.168.11.103:9042 [2023-03-17 14:33:35,901] INFO: New Cassandra host <Host: 192.168.11.103:9042 datacenter1> discovered [2023-03-17 14:33:35,901] DEBUG: Handling new host <Host: 192.168.11.103:9042 datacenter1> and notifying listeners [2023-03-17 14:33:35,901] DEBUG: Done preparing queries for new host <Host: 192.168.11.103:9042 datacenter1> [2023-03-17 14:33:35,901] DEBUG: Host 192.168.11.103:9042 is now marked up [2023-03-17 14:33:35,902] DEBUG: [control connection] Found new host to connect to: 192.168.83.114:9042 [2023-03-17 14:33:35,902] INFO: New Cassandra host <Host: 192.168.83.114:9042 datacenter1> discovered [2023-03-17 14:33:35,902] DEBUG: Handling new host <Host: 192.168.83.114:9042 datacenter1> and notifying listeners [2023-03-17 14:33:35,902] DEBUG: Done preparing queries for new host <Host: 192.168.83.114:9042 datacenter1> [2023-03-17 14:33:35,902] DEBUG: Host 192.168.83.114:9042 is now marked up [2023-03-17 14:33:35,902] DEBUG: [control connection] Finished fetching ring info [2023-03-17 14:33:35,902] DEBUG: [control connection] Rebuilding token map due to topology changes [2023-03-17 14:33:36,018] DEBUG: Control connection created [2023-03-17 14:33:36,019] DEBUG: Initializing connection for host 192.168.11.101:9042 [2023-03-17 14:33:36,019] DEBUG: Initializing connection for host 192.168.11.103:9042 [2023-03-17 14:33:36,020] DEBUG: Sending initial options message for new connection (140167826245280) to 192.168.11.101:9042 [2023-03-17 14:33:36,020] DEBUG: Sending initial options message for new connection (140167806303368) to 192.168.11.103:9042 [2023-03-17 14:33:36,020] DEBUG: Received options response on new connection (140167826245280) from 192.168.11.101:9042 [2023-03-17 14:33:36,021] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 14:33:36,021] DEBUG: Sending StartupMessage on <GeventConnection(140167826245280) 192.168.11.101:9042> [2023-03-17 14:33:36,021] DEBUG: Sent StartupMessage on <GeventConnection(140167826245280) 192.168.11.101:9042> [2023-03-17 14:33:36,021] DEBUG: Received options response on new connection (140167806303368) from 192.168.11.103:9042 [2023-03-17 14:33:36,021] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 14:33:36,021] DEBUG: Sending StartupMessage on <GeventConnection(140167806303368) 192.168.11.103:9042> [2023-03-17 14:33:36,021] DEBUG: Sent StartupMessage on <GeventConnection(140167806303368) 192.168.11.103:9042> [2023-03-17 14:33:36,022] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 14:33:36,022] DEBUG: Got ReadyMessage on new connection (140167826245280) from 192.168.11.101:9042 [2023-03-17 14:33:36,022] DEBUG: Finished initializing connection for host 192.168.11.101:9042 [2023-03-17 14:33:36,022] DEBUG: Added pool for host 192.168.11.101:9042 to session [2023-03-17 14:33:36,022] DEBUG: Initializing connection for host 192.168.83.114:9042 [2023-03-17 14:33:36,022] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 14:33:36,022] DEBUG: Got ReadyMessage on new connection (140167806303368) from 192.168.11.103:9042 [2023-03-17 14:33:36,022] DEBUG: Finished initializing connection for host 192.168.11.103:9042 [2023-03-17 14:33:36,023] DEBUG: Added pool for host 192.168.11.103:9042 to session [2023-03-17 14:33:36,023] DEBUG: Not starting MonitorReporter thread for Insights; not supported by server version 3.11.13 on ControlConnection host 192.168.11.101:9042 [2023-03-17 14:33:36,023] DEBUG: Started Session with client_id 973d9dbb-236a-4d82-82fb-40a1bcf9a94f and session_id bceebb3e-544f-4786-b28c-729253e46e46 [2023-03-17 14:33:36,065] DEBUG: Checking placement using dc and rack... [2023-03-17 14:33:36,065] INFO: Resolving ip address 192.168.11.101 [2023-03-17 14:33:36,065] INFO: ip address to resolve 192.168.11.101 [2023-03-17 14:33:36,065] DEBUG: Sending initial options message for new connection (140167806301464) to 192.168.83.114:9042 [2023-03-17 14:33:36,066] DEBUG: Resolved 192.168.11.101 to cassandra02 [2023-03-17 14:33:36,066] DEBUG: Checking host 192.168.11.101 against 192.168.11.101/cassandra02 [2023-03-17 14:33:36,067] INFO: Resolving ip address 192.168.11.101 [2023-03-17 14:33:36,067] INFO: ip address to resolve 192.168.11.101 [2023-03-17 14:33:36,067] DEBUG: Resolved 192.168.11.101 to cassandra02 [2023-03-17 14:33:36,067] INFO: Resolving ip address 192.168.11.103 [2023-03-17 14:33:36,067] INFO: ip address to resolve 192.168.11.103 [2023-03-17 14:33:36,067] DEBUG: Received options response on new connection (140167806301464) from 192.168.83.114:9042 [2023-03-17 14:33:36,067] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 14:33:36,067] DEBUG: Sending StartupMessage on <GeventConnection(140167806301464) 192.168.83.114:9042> [2023-03-17 14:33:36,067] DEBUG: Sent StartupMessage on <GeventConnection(140167806301464) 192.168.83.114:9042> [2023-03-17 14:33:36,067] DEBUG: Resolved 192.168.11.103 to cassandra01 [2023-03-17 14:33:36,068] INFO: Resolving ip address 192.168.83.114 [2023-03-17 14:33:36,068] INFO: ip address to resolve 192.168.83.114 [2023-03-17 14:33:36,068] DEBUG: Resolved 192.168.83.114 to cassandra03 [2023-03-17 14:33:36,068] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 14:33:36,068] DEBUG: Got ReadyMessage on new connection (140167806301464) from 192.168.83.114:9042 [2023-03-17 14:33:36,068] DEBUG: Finished initializing connection for host 192.168.83.114:9042 [2023-03-17 14:33:36,068] DEBUG: Added pool for host 192.168.83.114:9042 to session [2023-03-17 14:33:36,069] DEBUG: Closing connection (140167826245280) to 192.168.11.101:9042 [2023-03-17 14:33:36,069] DEBUG: Closed socket to 192.168.11.101:9042 [2023-03-17 14:33:36,069] DEBUG: Closing connection (140167806303368) to 192.168.11.103:9042 [2023-03-17 14:33:36,069] DEBUG: Closed socket to 192.168.11.103:9042 [2023-03-17 14:33:36,069] DEBUG: Closing connection (140167806301464) to 192.168.83.114:9042 [2023-03-17 14:33:36,069] DEBUG: Closed socket to 192.168.83.114:9042 [2023-03-17 14:33:36,069] DEBUG: Shutting down Cluster Scheduler [2023-03-17 14:33:36,070] DEBUG: Shutting down control connection [2023-03-17 14:33:36,070] DEBUG: Closing connection (140167815166048) to 192.168.11.101:9042 [2023-03-17 14:33:36,070] DEBUG: Closed socket to 192.168.11.101:9042 [2023-03-17 14:33:36,162] DEBUG: Blob cassandra02/20230317011/meta/tokenmap.json was not found in cache. [2023-03-17 14:33:36,163] DEBUG: [Storage] Getting object cassandra02/20230317011/meta/tokenmap.json [2023-03-17 14:33:36,163] DEBUG: [Storage] Reading blob cassandra02/20230317011/meta/tokenmap.json... [2023-03-17 14:33:36,163] DEBUG: [Storage] Reading blob cassandra02/20230317011/meta/tokenmap.json... [2023-03-17 14:33:36,182] DEBUG: [Storage] Getting object cassandra02/20230317011/meta/schema.cql [2023-03-17 14:33:36,183] DEBUG: [Storage] Reading blob cassandra02/20230317011/meta/schema.cql... [2023-03-17 14:33:36,183] DEBUG: [Storage] Reading blob cassandra02/20230317011/meta/schema.cql... [2023-03-17 14:33:36,316] DEBUG: Blob cassandra02/20230317011/meta/schema.cql was not found in cache. [2023-03-17 14:33:36,316] DEBUG: [Storage] Getting object cassandra02/20230317011/meta/schema.cql [2023-03-17 14:33:36,328] DEBUG: [Storage] Getting object index/latest_backup/cassandra02/backup_name.txt [2023-03-17 14:33:36,328] DEBUG: [Storage] Getting object cassandra02/None/meta/differential [2023-03-17 14:33:36,328] DEBUG: [Storage] Getting object cassandra02/None/meta/incremental [2023-03-17 14:33:36,328] INFO: Node cassandra02 does not have latest backup [2023-03-17 14:33:36,329] INFO: Creating snapshot [2023-03-17 14:33:36,329] DEBUG: Executing: nodetool -Dcom.sun.jndi.rmiURLParsing=legacy -u cassandra -pw cassandra snapshot -t medusa-20230317011 error: Snapshot medusa-20230317011 already exists. -- StackTrace -- java.io.IOException: Snapshot medusa-20230317011 already exists. at org.apache.cassandra.service.StorageService.takeSnapshot(StorageService.java:3327) at org.apache.cassandra.service.StorageService.takeSnapshot(StorageService.java:3241) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:71) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:275) at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:112) at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:46) at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237) at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138) at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819) at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801) at javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1468) at javax.management.remote.rmi.RMIConnectionImpl.access$300(RMIConnectionImpl.java:76) at javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1309) at javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1401) at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:829) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357) at sun.rmi.transport.Transport$1.run(Transport.java:200) at sun.rmi.transport.Transport$1.run(Transport.java:197) at java.security.AccessController.doPrivileged(Native Method) at sun.rmi.transport.Transport.serviceCall(Transport.java:196) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:573) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:834) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:688) at java.security.AccessController.doPrivileged(Native Method) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:687) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
[2023-03-17 14:33:37,070] ERROR: Issue occurred inside handle_backup Name: 20230317011 Error: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-20230317011']' returned non-zero exit status 2. [2023-03-17 14:33:37,070] INFO: Updated from existing status: 0 to new status: 2 for backup id: 20230317011 [2023-03-17 14:33:37,070] ERROR: Error occurred during backup: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-20230317011']' returned non-zero exit status 2. Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 197, in handle_backup enable_md5_checks_flag, backup_name, config, monitoring) File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 250, in start_backup cassandra, node_backup, storage, differential_mode, enable_md5, config, backup_name) File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 294, in do_backup with cassandra.create_snapshot(backup_name) as snapshot: File "/usr/local/lib/python3.6/site-packages/medusa/cassandra_utils.py", line 449, in create_snapshot self.snapshot_service.create_snapshot(tag=tag) File "/usr/local/lib/python3.6/site-packages/medusa/service/snapshot/nodetool_snapshot_service.py", line 32, in create_snapshot subprocess.check_call(cmd, stdout=subprocess.DEVNULL, universal_newlines=True) File "/usr/local/lib64/python3.6/site-packages/gevent/subprocess.py", line 350, in check_call raise CalledProcessError(retcode, cmd) # pylint:disable=undefined-variable subprocess.CalledProcessError: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-20230317011']' returned non-zero exit status 2. [root@cassandra02 medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6]#
@adejanovski mogul, please take a look
Hi @liaohongqing-A, I'm sorry but this ticket is unreadable. Please provide a description of your configuration and steps to reproduce the issue. Also try to provide logs as attachments unless you want to highlight just a few specific lines. Please use proper code formatting for your commands outputs as well, enclosing them between three backticks.
Project board link
①Physical machinehosts config [root@cassandra01 ~]# cat /etc/hosts 192.168.11.103 cassandra01 192.168.11.101 cassandra02 192.168.83.114 cassandra03 [root@cassandra01 ~]# [root@cassandra01 ~]# nodetool version ReleaseVersion: 3.11.13 [root@cassandra01 ~]# medusa --version
0.14.0 [root@cassandra01 ~]# python3 -V
Python 3.6.8 [root@cassandra01 ~]# cat /etc/redhat-release CentOS Linux release 7.8.2003 (Core) [root@cassandra01 ~]#
②medusa config [root@cassandra01 ~]# cat /etc/medusa/medusa.ini | egrep -v "#|^$|;" [cassandra] config_file = /var/lib/cassandra/conf/cassandra.yaml cql_username = cassandra cql_password = cassandra nodetool_username = cassandra nodetool_password = cassandra resolve_ip_addresses = True [storage] storage_provider = local bucket_name = cassandra_backups base_path = /opt/cassandrabackups max_backup_age = 0 max_backup_count = 0 transfer_max_bandwidth = 50MB/s concurrent_transfers = 1 multi_part_upload_threshold = 104857600 backup_grace_period_in_days = 10 use_sudo_for_restore = True [monitoring] [ssh] username = root key_file = /root/.ssh/id_rsa [checks] [logging] [grpc] [kubernetes] [root@cassandra01 ~]#
③cassandra config [root@cassandra01 ~]# cat /var/lib/cassandra/conf/cassandra.yaml | egrep -v "#|^$|;" cluster_name: 'Test Cluster' num_tokens: 256 hinted_handoff_enabled: true hinted_handoff_throttle_in_kb: 1024 max_hints_delivery_threads: 2 hints_flush_period_in_ms: 10000 max_hints_file_size_in_mb: 128 batchlog_replay_throttle_in_kb: 1024 authenticator: AllowAllAuthenticator authorizer: AllowAllAuthorizer role_manager: CassandraRoleManager roles_validity_in_ms: 2000 permissions_validity_in_ms: 2000 credentials_validity_in_ms: 2000 partitioner: org.apache.cassandra.dht.Murmur3Partitioner cdc_enabled: false disk_failure_policy: stop commit_failure_policy: stop prepared_statements_cache_size_mb: thrift_prepared_statements_cache_size_mb: key_cache_size_in_mb: key_cache_save_period: 14400 row_cache_size_in_mb: 0 row_cache_save_period: 0 counter_cache_size_in_mb: counter_cache_save_period: 7200 commitlog_sync: periodic commitlog_sync_period_in_ms: 10000 commitlog_segment_size_in_mb: 32 seed_provider:
④medusa backup-cluster Error Log [root@cassandra01 ~]# medusa backup-cluster --backup-name=20230317011 --mode=full [2023-03-17 14:33:31,676] INFO: Resolving ip address [2023-03-17 14:33:31,677] INFO: ip address to resolve 192.168.11.103 [2023-03-17 14:33:31,678] INFO: Monitoring provider is noop [2023-03-17 14:33:31,681] INFO: Starting backup 20230317011 [2023-03-17 14:33:32,085] INFO: Resolving ip address 192.168.11.103 [2023-03-17 14:33:32,085] INFO: ip address to resolve 192.168.11.103 [2023-03-17 14:33:32,086] INFO: Resolving ip address 192.168.11.101 [2023-03-17 14:33:32,086] INFO: ip address to resolve 192.168.11.101 [2023-03-17 14:33:32,086] INFO: Resolving ip address 192.168.11.103 [2023-03-17 14:33:32,086] INFO: ip address to resolve 192.168.11.103 [2023-03-17 14:33:32,086] INFO: Resolving ip address 192.168.83.114 [2023-03-17 14:33:32,087] INFO: ip address to resolve 192.168.83.114 [2023-03-17 14:33:32,088] INFO: Creating snapshots on all nodes [2023-03-17 14:33:32,088] INFO: Executing "nodetool -Dcom.sun.jndi.rmiURLParsing=legacy -u cassandra -pw cassandra snapshot -t medusa-20230317011" on following nodes ['cassandra02', 'cassandra01', 'cassandra03'] with a parallelism/pool size of 500 [2023-03-17 14:33:34,843] INFO: Job executing "nodetool -Dcom.sun.jndi.rmiURLParsing=legacy -u cassandra -pw cassandra snapshot -t medusa-20230317011" ran and finished Successfully on all nodes. [2023-03-17 14:33:34,844] INFO: A snapshot medusa-20230317011 was created on all nodes. [2023-03-17 14:33:34,844] INFO: Uploading snapshots from nodes to external storage [2023-03-17 14:33:34,845] INFO: Executing "mkdir -p /tmp/medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6; cd /tmp/medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6 && medusa-wrapper sudo medusa -vvv backup-node --backup-name 20230317011 --mode full" on following nodes ['cassandra02', 'cassandra01', 'cassandra03'] with a parallelism/pool size of 1 [2023-03-17 14:33:42,219] ERROR: Job executing "mkdir -p /tmp/medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6; cd /tmp/medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6 && medusa-wrapper sudo medusa -vvv backup-node --backup-name 20230317011 --mode full" ran and finished with errors on following nodes: ['cassandra01', 'cassandra02', 'cassandra03'] [2023-03-17 14:33:42,220] ERROR: Some nodes failed to upload the backup. [2023-03-17 14:33:42,221] ERROR: This error happened during the cluster backup: Some nodes failed to upload the backup. Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/medusa/backup_cluster.py", line 64, in orchestrate backup.execute(cql_session_provider) File "/usr/local/lib/python3.6/site-packages/medusa/backup_cluster.py", line 150, in execute self._upload_backup() File "/usr/local/lib/python3.6/site-packages/medusa/backup_cluster.py", line 177, in _upload_backup raise Exception(err_msg) Exception: Some nodes failed to upload the backup. [2023-03-17 14:33:42,222] ERROR: Something went wrong! Attempting to clean snapshots and exit. [2023-03-17 14:33:42,222] INFO: Executing "nodetool -Dcom.sun.jndi.rmiURLParsing=legacy -u cassandra -pw cassandra clearsnapshot -t medusa-20230317011" on following nodes ['cassandra02', 'cassandra01', 'cassandra03'] with a parallelism/pool size of 1 [2023-03-17 14:33:46,708] INFO: Job executing "nodetool -Dcom.sun.jndi.rmiURLParsing=legacy -u cassandra -pw cassandra clearsnapshot -t medusa-20230317011" ran and finished Successfully on all nodes. [2023-03-17 14:33:46,708] INFO: All nodes successfully cleared their snapshot. [root@cassandra01 ~]#
⑤medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6/stderr [root@cassandra01 ~]# cat /tmp/medusa-job-458e422d-a0e8-404f-b70a-f6cbcf2b97b6/stderr [2023-03-17 14:33:38,543] DEBUG: Loading configuration from /etc/medusa/medusa.ini [2023-03-17 14:33:38,545] INFO: Resolving ip address [2023-03-17 14:33:38,545] INFO: ip address to resolve 192.168.11.103 [2023-03-17 14:33:38,545] DEBUG: Resolved 192.168.11.103 to cassandra01 [2023-03-17 14:33:38,546] INFO: Registered backup id 20230317011 [2023-03-17 14:33:38,546] INFO: Monitoring provider is noop [2023-03-17 14:33:38,546] DEBUG: Starting backup preparations with Mode: full [2023-03-17 14:33:38,546] DEBUG: Loading storage_provider: local [2023-03-17 14:33:38,555] DEBUG: This server has systemd: True [2023-03-17 14:33:38,746] DEBUG: Blob cassandra01/20230317011/meta/schema.cql was not found in cache. [2023-03-17 14:33:38,746] DEBUG: [Storage] Getting object cassandra01/20230317011/meta/schema.cql [2023-03-17 14:33:38,746] INFO: Starting backup using Stagger: None Mode: full Name: 20230317011 [2023-03-17 14:33:38,746] INFO: Updated from existing status: -1 to new status: 0 for backup id: 20230317011 [2023-03-17 14:33:38,747] DEBUG: Process psutil.Process(pid=12896, name='medusa', status='running', started='14:33:37') was set to use only idle IO and CPU resources [2023-03-17 14:33:38,747] INFO: Saving tokenmap and schema [2023-03-17 14:33:38,748] DEBUG: Connecting to cluster, contact points: ['192.168.11.103']; protocol version: 66 [2023-03-17 14:33:38,748] DEBUG: Host 192.168.11.103:9042 is now marked up [2023-03-17 14:33:38,749] DEBUG: [control connection] Opening new connection to 192.168.11.103:9042 [2023-03-17 14:33:38,750] DEBUG: Sending initial options message for new connection (140581168622336) to 192.168.11.103:9042 [2023-03-17 14:33:38,751] DEBUG: Defuncting connection (140581168622336) to 192.168.11.103:9042: <Error from server: code=000a [Protocol error] message="Invalid or unsupported protocol version (66); supported versions are (3/v3, 4/v4, 5/v5-beta)"> [2023-03-17 14:33:38,751] DEBUG: Closing connection (140581168622336) to 192.168.11.103:9042 [2023-03-17 14:33:38,751] DEBUG: Closed socket to 192.168.11.103:9042 [2023-03-17 14:33:38,751] DEBUG: Exception in read for <GeventConnection(140581168622336) 192.168.11.103:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 14:33:38,752] WARNING: Downgrading core protocol version from 66 to 65 for 192.168.11.103:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 14:33:38,752] DEBUG: Sending initial options message for new connection (140581168665376) to 192.168.11.103:9042 [2023-03-17 14:33:38,752] DEBUG: Defuncting connection (140581168665376) to 192.168.11.103:9042: <Error from server: code=000a [Protocol error] message="Invalid or unsupported protocol version (65); supported versions are (3/v3, 4/v4, 5/v5-beta)"> [2023-03-17 14:33:38,753] DEBUG: Closing connection (140581168665376) to 192.168.11.103:9042 [2023-03-17 14:33:38,753] DEBUG: Closed socket to 192.168.11.103:9042 [2023-03-17 14:33:38,753] DEBUG: Exception in read for <GeventConnection(140581168665376) 192.168.11.103:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 14:33:38,753] WARNING: Downgrading core protocol version from 65 to 5 for 192.168.11.103:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 14:33:38,753] DEBUG: Sending initial options message for new connection (140581168668176) to 192.168.11.103:9042 [2023-03-17 14:33:38,754] ERROR: Closing connection <GeventConnection(140581168668176) 192.168.11.103:9042> due to protocol error: Error from server: code=000a [Protocol error] message="Beta version of the protocol used (5/v5-beta), but USE_BETA flag is unset" [2023-03-17 14:33:38,754] DEBUG: Defuncting connection (140581168668176) to 192.168.11.103:9042: <Error from server: code=000a [Protocol error] message="Beta version of the protocol used (5/v5-beta), but USE_BETA flag is unset"> [2023-03-17 14:33:38,754] DEBUG: Closing connection (140581168668176) to 192.168.11.103:9042 [2023-03-17 14:33:38,754] DEBUG: Closed socket to 192.168.11.103:9042 [2023-03-17 14:33:38,754] DEBUG: Exception in read for <GeventConnection(140581168668176) 192.168.11.103:9042 (defunct)>: [Errno 9] Bad file descriptor [2023-03-17 14:33:38,754] WARNING: Downgrading core protocol version from 5 to 4 for 192.168.11.103:9042. To avoid this, it is best practice to explicitly set Cluster(protocol_version) to the version supported by your cluster. http://datastax.github.io/python-driver/api/cassandra/cluster.html#cassandra.cluster.Cluster.protocol_version [2023-03-17 14:33:38,755] DEBUG: Sending initial options message for new connection (140581168664872) to 192.168.11.103:9042 [2023-03-17 14:33:38,755] DEBUG: Received options response on new connection (140581168664872) from 192.168.11.103:9042 [2023-03-17 14:33:38,755] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 14:33:38,755] DEBUG: Sending StartupMessage on <GeventConnection(140581168664872) 192.168.11.103:9042> [2023-03-17 14:33:38,756] DEBUG: Sent StartupMessage on <GeventConnection(140581168664872) 192.168.11.103:9042> [2023-03-17 14:33:38,757] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 14:33:38,757] DEBUG: Got ReadyMessage on new connection (140581168664872) from 192.168.11.103:9042 [2023-03-17 14:33:38,757] DEBUG: [control connection] Established new connection <GeventConnection(140581168664872) 192.168.11.103:9042>, registering watchers and refreshing schema and topology [2023-03-17 14:33:38,761] DEBUG: [control connection] Refreshing node list and token map using preloaded results [2023-03-17 14:33:38,762] INFO: Using datacenter 'datacenter1' for DCAwareRoundRobinPolicy (via host '192.168.11.103:9042'); if incorrect, please specify a local_dc to the constructor, or limit contact points to local cluster nodes [2023-03-17 14:33:38,762] DEBUG: [control connection] Found new host to connect to: 192.168.83.114:9042 [2023-03-17 14:33:38,762] INFO: New Cassandra host <Host: 192.168.83.114:9042 datacenter1> discovered [2023-03-17 14:33:38,762] DEBUG: Handling new host <Host: 192.168.83.114:9042 datacenter1> and notifying listeners [2023-03-17 14:33:38,762] DEBUG: Done preparing queries for new host <Host: 192.168.83.114:9042 datacenter1> [2023-03-17 14:33:38,762] DEBUG: Host 192.168.83.114:9042 is now marked up [2023-03-17 14:33:38,762] DEBUG: [control connection] Found new host to connect to: 192.168.11.101:9042 [2023-03-17 14:33:38,762] INFO: New Cassandra host <Host: 192.168.11.101:9042 datacenter1> discovered [2023-03-17 14:33:38,762] DEBUG: Handling new host <Host: 192.168.11.101:9042 datacenter1> and notifying listeners [2023-03-17 14:33:38,763] DEBUG: Done preparing queries for new host <Host: 192.168.11.101:9042 datacenter1> [2023-03-17 14:33:38,763] DEBUG: Host 192.168.11.101:9042 is now marked up [2023-03-17 14:33:38,763] DEBUG: [control connection] Finished fetching ring info [2023-03-17 14:33:38,763] DEBUG: [control connection] Rebuilding token map due to topology changes [2023-03-17 14:33:38,857] DEBUG: Control connection created [2023-03-17 14:33:38,857] DEBUG: Initializing connection for host 192.168.11.103:9042 [2023-03-17 14:33:38,858] DEBUG: Initializing connection for host 192.168.83.114:9042 [2023-03-17 14:33:38,858] DEBUG: Sending initial options message for new connection (140581168622840) to 192.168.11.103:9042 [2023-03-17 14:33:38,859] DEBUG: Sending initial options message for new connection (140581159274424) to 192.168.83.114:9042 [2023-03-17 14:33:38,859] DEBUG: Received options response on new connection (140581168622840) from 192.168.11.103:9042 [2023-03-17 14:33:38,859] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 14:33:38,859] DEBUG: Sending StartupMessage on <GeventConnection(140581168622840) 192.168.11.103:9042> [2023-03-17 14:33:38,859] DEBUG: Sent StartupMessage on <GeventConnection(140581168622840) 192.168.11.103:9042> [2023-03-17 14:33:38,860] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 14:33:38,860] DEBUG: Got ReadyMessage on new connection (140581168622840) from 192.168.11.103:9042 [2023-03-17 14:33:38,860] DEBUG: Finished initializing connection for host 192.168.11.103:9042 [2023-03-17 14:33:38,860] DEBUG: Added pool for host 192.168.11.103:9042 to session [2023-03-17 14:33:38,860] DEBUG: Initializing connection for host 192.168.11.101:9042 [2023-03-17 14:33:38,861] DEBUG: Received options response on new connection (140581159274424) from 192.168.83.114:9042 [2023-03-17 14:33:38,861] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 14:33:38,861] DEBUG: Sending StartupMessage on <GeventConnection(140581159274424) 192.168.83.114:9042> [2023-03-17 14:33:38,861] DEBUG: Sent StartupMessage on <GeventConnection(140581159274424) 192.168.83.114:9042> [2023-03-17 14:33:38,862] DEBUG: Sending initial options message for new connection (140581159268024) to 192.168.11.101:9042 [2023-03-17 14:33:38,862] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 14:33:38,862] DEBUG: Got ReadyMessage on new connection (140581159274424) from 192.168.83.114:9042 [2023-03-17 14:33:38,862] DEBUG: Finished initializing connection for host 192.168.83.114:9042 [2023-03-17 14:33:38,862] DEBUG: Added pool for host 192.168.83.114:9042 to session [2023-03-17 14:33:38,862] DEBUG: Not starting MonitorReporter thread for Insights; not supported by server version 3.11.13 on ControlConnection host 192.168.11.103:9042 [2023-03-17 14:33:38,862] DEBUG: Started Session with client_id a584715a-f396-4066-bc83-57d68aca8ede and session_id 36760d93-3e55-43d8-b389-744296d42406 [2023-03-17 14:33:38,905] DEBUG: Checking placement using dc and rack... [2023-03-17 14:33:38,905] DEBUG: Received options response on new connection (140581159268024) from 192.168.11.101:9042 [2023-03-17 14:33:38,905] DEBUG: No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['snappy', 'lz4'] [2023-03-17 14:33:38,905] DEBUG: Sending StartupMessage on <GeventConnection(140581159268024) 192.168.11.101:9042> [2023-03-17 14:33:38,905] DEBUG: Sent StartupMessage on <GeventConnection(140581159268024) 192.168.11.101:9042> [2023-03-17 14:33:38,906] INFO: Resolving ip address 192.168.11.103 [2023-03-17 14:33:38,906] INFO: ip address to resolve 192.168.11.103 [2023-03-17 14:33:38,906] DEBUG: Resolved 192.168.11.103 to cassandra01 [2023-03-17 14:33:38,906] DEBUG: Checking host 192.168.11.103 against 192.168.11.103/cassandra01 [2023-03-17 14:33:38,907] INFO: Resolving ip address 192.168.11.101 [2023-03-17 14:33:38,907] INFO: ip address to resolve 192.168.11.101 [2023-03-17 14:33:38,907] WARNING: An authentication challenge was not sent, this is suspicious because the driver expects authentication (configured authenticator = PlainTextAuthenticator) [2023-03-17 14:33:38,907] DEBUG: Got ReadyMessage on new connection (140581159268024) from 192.168.11.101:9042 [2023-03-17 14:33:38,907] DEBUG: Finished initializing connection for host 192.168.11.101:9042 [2023-03-17 14:33:38,907] DEBUG: Added pool for host 192.168.11.101:9042 to session [2023-03-17 14:33:38,907] DEBUG: Resolved 192.168.11.101 to cassandra02 [2023-03-17 14:33:38,908] INFO: Resolving ip address 192.168.11.103 [2023-03-17 14:33:38,908] INFO: ip address to resolve 192.168.11.103 [2023-03-17 14:33:38,908] DEBUG: Resolved 192.168.11.103 to cassandra01 [2023-03-17 14:33:38,908] INFO: Resolving ip address 192.168.83.114 [2023-03-17 14:33:38,908] INFO: ip address to resolve 192.168.83.114 [2023-03-17 14:33:38,908] DEBUG: Resolved 192.168.83.114 to cassandra03 [2023-03-17 14:33:38,908] DEBUG: Closing connection (140581168622840) to 192.168.11.103:9042 [2023-03-17 14:33:38,908] DEBUG: Closed socket to 192.168.11.103:9042 [2023-03-17 14:33:38,909] DEBUG: Closing connection (140581159274424) to 192.168.83.114:9042 [2023-03-17 14:33:38,909] DEBUG: Closed socket to 192.168.83.114:9042 [2023-03-17 14:33:38,909] DEBUG: Closing connection (140581159268024) to 192.168.11.101:9042 [2023-03-17 14:33:38,909] DEBUG: Closed socket to 192.168.11.101:9042 [2023-03-17 14:33:38,909] DEBUG: Shutting down Cluster Scheduler [2023-03-17 14:33:38,909] DEBUG: Shutting down control connection [2023-03-17 14:33:38,909] DEBUG: Closing connection (140581168664872) to 192.168.11.103:9042 [2023-03-17 14:33:38,909] DEBUG: Closed socket to 192.168.11.103:9042 [2023-03-17 14:33:38,917] DEBUG: Blob cassandra01/20230317011/meta/tokenmap.json was not found in cache. [2023-03-17 14:33:38,917] DEBUG: [Storage] Getting object cassandra01/20230317011/meta/tokenmap.json [2023-03-17 14:33:38,917] DEBUG: [Storage] Reading blob cassandra01/20230317011/meta/tokenmap.json... [2023-03-17 14:33:38,917] DEBUG: [Storage] Reading blob cassandra01/20230317011/meta/tokenmap.json... [2023-03-17 14:33:38,918] DEBUG: [Storage] Getting object cassandra01/20230317011/meta/schema.cql [2023-03-17 14:33:38,918] DEBUG: [Storage] Reading blob cassandra01/20230317011/meta/schema.cql... [2023-03-17 14:33:38,918] DEBUG: [Storage] Reading blob cassandra01/20230317011/meta/schema.cql... [2023-03-17 14:33:38,926] DEBUG: Blob cassandra01/20230317011/meta/schema.cql was not found in cache. [2023-03-17 14:33:38,926] DEBUG: [Storage] Getting object cassandra01/20230317011/meta/schema.cql [2023-03-17 14:33:38,926] DEBUG: [Storage] Getting object index/latest_backup/cassandra01/backup_name.txt [2023-03-17 14:33:38,926] DEBUG: [Storage] Getting object cassandra01/None/meta/differential [2023-03-17 14:33:38,926] DEBUG: [Storage] Getting object cassandra01/None/meta/incremental [2023-03-17 14:33:38,927] INFO: Node cassandra01 does not have latest backup [2023-03-17 14:33:38,927] INFO: Creating snapshot [2023-03-17 14:33:38,927] DEBUG: Executing: nodetool -Dcom.sun.jndi.rmiURLParsing=legacy -u cassandra -pw cassandra snapshot -t medusa-20230317011 error: Snapshot medusa-20230317011 already exists. -- StackTrace -- java.io.IOException: Snapshot medusa-20230317011 already exists. at org.apache.cassandra.service.StorageService.takeSnapshot(StorageService.java:3327) at org.apache.cassandra.service.StorageService.takeSnapshot(StorageService.java:3241) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:71) at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:275) at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:112) at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:46) at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237) at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138) at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819) at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801) at javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1468) at javax.management.remote.rmi.RMIConnectionImpl.access$300(RMIConnectionImpl.java:76) at javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1309) at javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1401) at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:829) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357) at sun.rmi.transport.Transport$1.run(Transport.java:200) at sun.rmi.transport.Transport$1.run(Transport.java:197) at java.security.AccessController.doPrivileged(Native Method) at sun.rmi.transport.Transport.serviceCall(Transport.java:196) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:573) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:834) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:688) at java.security.AccessController.doPrivileged(Native Method) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:687) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) [2023-03-17 14:33:39,676] ERROR: Issue occurred inside handle_backup Name: 20230317011 Error: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-20230317011']' returned non-zero exit status 2. [2023-03-17 14:33:39,677] INFO: Updated from existing status: 0 to new status: 2 for backup id: 20230317011 [2023-03-17 14:33:39,677] ERROR: Error occurred during backup: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-20230317011']' returned non-zero exit status 2. Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 197, in handle_backup enable_md5_checks_flag, backup_name, config, monitoring) File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 250, in start_backup cassandra, node_backup, storage, differential_mode, enable_md5, config, backup_name) File "/usr/local/lib/python3.6/site-packages/medusa/backup_node.py", line 294, in do_backup with cassandra.create_snapshot(backup_name) as snapshot: File "/usr/local/lib/python3.6/site-packages/medusa/cassandra_utils.py", line 449, in create_snapshot self.snapshot_service.create_snapshot(tag=tag) File "/usr/local/lib/python3.6/site-packages/medusa/service/snapshot/nodetool_snapshot_service.py", line 32, in create_snapshot subprocess.check_call(cmd, stdout=subprocess.DEVNULL, universal_newlines=True) File "/usr/local/lib64/python3.6/site-packages/gevent/subprocess.py", line 350, in check_call raise CalledProcessError(retcode, cmd) # pylint:disable=undefined-variable subprocess.CalledProcessError: Command '['nodetool', '-Dcom.sun.jndi.rmiURLParsing=legacy', '-u', 'cassandra', '-pw', 'cassandra', 'snapshot', '-t', 'medusa-20230317011']' returned non-zero exit status 2. [root@cassandra01 ~]#