[Bug] Apache IoTDB confignode - unable to start pod on OpenShift

180Gio commented 2 months ago

Search before asking

[X] I searched in the issues and found nothing similar.

Version

1.3.2-confignode, 1.3.2-standalone, OS: Windows and OpenShift 4.16

Describe the bug and provide the minimal reproduce step

ApacheIoTDB is unable to start in OpenShift due to error on creation of folder

----------------------------
Starting IoTDB ConfigNode
----------------------------
Notice: in some systems, ConfigNode must run in sudo mode to write data. The process may fail.
Checking whether the ports are already occupied...
Warning: If you do not use sudo, the checking may not detect all the occupied ports.
WARN:
WARN: the value of net.core.somaxconn (=4096) is too small, please set it to a larger value using the following command.
WARN:     sudo sysctl -w net.core.somaxconn=65535
WARN: The original net.core.somaxconn value will be set back when the os reboots.
WARN:
setting local JMX...
ConfigNode on heap memory size = 6552MB, off heap memory size = 1640MB
If you want to change this configuration, please check conf/confignode-env.sh.
2024-09-11 12:56:25,088 [main] INFO  o.a.i.c.c.ConfigNodeDescriptor:107 - Start to read config file file:/iotdb/sbin/../conf/iotdb-common.properties 
2024-09-11 12:56:25,094 [main] INFO  o.a.i.c.c.ConfigNodeDescriptor:129 - start reading ConfigNode conf file: file:/iotdb/sbin/../conf/iotdb-confignode.properties 
2024-09-11 12:56:25,166 [main] INFO  o.a.i.c.s.ConfigNode:106 - IoTDB-ConfigNode environment variables: 
    CONFIGNODE_HOME=/iotdb/sbin/..;
    CONFIGNODE_CONF=/iotdb/sbin/../conf; 
2024-09-11 12:56:25,167 [main] INFO  o.a.i.c.s.ConfigNode:110 - IoTDB-ConfigNode default charset is: UTF-8 
2024-09-11 12:56:25,169 [main] INFO  o.a.i.c.s.ConfigNodeCommandLine:68 - Running mode -s 
2024-09-11 12:56:25,170 [main] INFO  o.a.i.c.s.ConfigNodeCommandLine:72 - Starting IoTDB 1.3.1 (Build: 214695d) 
2024-09-11 12:56:25,173 [main] INFO  o.a.i.c.c.ConfigNodeStartupCheck:65 - configNode port check successful. 
2024-09-11 12:56:25,174 [main] INFO  o.a.i.c.s.StartupChecks:59 - Start JMX locally. 
2024-09-11 12:56:25,175 [main] INFO  o.a.i.c.s.StartupChecks:45 - JDK version is 11. 
2024-09-11 12:56:25,175 [main] INFO  o.a.i.c.c.ConfigNodeStartupCheck:201 - Make dirs: /iotdb/sbin/../data/confignode/system 
2024-09-11 12:56:25,176 [main] INFO  o.a.i.c.c.ConfigNodeStartupCheck:201 - Make dirs: /iotdb/sbin/../data/confignode/consensus 
2024-09-11 12:56:25,183 [main] INFO  o.a.i.c.s.ConfigNode:118 - Activating IoTDB-ConfigNode... 
2024-09-11 12:56:25,184 [main] INFO  o.a.i.c.s.RegisterManager:54 - The JMX ServerService service is started successfully, which takes 0 ms. 
2024-09-11 12:56:25,496 [main] INFO  o.a.i.c.s.ConfigNode:251 - Successfully setup internal services. 
2024-09-11 12:56:25,588 [main] INFO  o.a.i.c.a.a.BasicAuthorizer$InstanceHolder:104 - Authorizer provider class: org.apache.iotdb.commons.auth.authorizer.LocalFileAuthorizer 
2024-09-11 12:56:25,592 [main] INFO  o.a.i.c.a.u.LocalFileUserAccessor:399 - user info dir /iotdb/data/confignode/system/users is created 
2024-09-11 12:56:25,688 [main] INFO  o.a.i.c.a.u.BasicUserManager:129 - Admin initialized 
2024-09-11 12:56:25,690 [main] INFO  o.a.i.c.a.r.LocalFileRoleAccessor:270 - role info dir /iotdb/data/confignode/system/roles is created 
2024-09-11 12:56:25,723 [main] ERROR o.a.i.c.s.ConfigNode:299 - Can't start ConfigNode consensus group! 
java.io.IOException: Cannot create directory '/iotdb/sbin/../ext/udf/tmp'.
    at org.apache.commons.io.FileUtils.mkdirs(FileUtils.java:2287)
    at org.apache.commons.io.FileUtils.forceMkdir(FileUtils.java:1380)
    at org.apache.iotdb.commons.file.SystemFileFactory.makeDirIfNecessary(SystemFileFactory.java:82)
    at org.apache.iotdb.commons.udf.service.UDFExecutableManager.setupAndGetInstance(UDFExecutableManager.java:48)
    at org.apache.iotdb.confignode.persistence.UDFInfo.<init>(UDFInfo.java:78)
    at org.apache.iotdb.confignode.manager.ConfigManager.<init>(ConfigManager.java:261)
    at org.apache.iotdb.confignode.service.ConfigNode.initConfigManager(ConfigNode.java:297)
    at org.apache.iotdb.confignode.service.ConfigNode.active(ConfigNode.java:127)
    at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.activeConfigNodeInstance(ConfigNodeCommandLine.java:97)
    at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.run(ConfigNodeCommandLine.java:79)
    at org.apache.iotdb.commons.ServerCommandLine.doMain(ServerCommandLine.java:58)
    at org.apache.iotdb.confignode.service.ConfigNode.main(ConfigNode.java:114)
2024-09-11 12:56:25,724 [main] INFO  o.a.i.c.s.ConfigNode:409 - Deactivating IoTDB-ConfigNode... 
2024-09-11 12:56:25,724 [main] INFO  o.a.i.c.s.RegisterManager:73 - deregister all service. 
2024-09-11 12:56:25,724 [main] INFO  o.a.i.c.s.ConfigNode:415 - IoTDB-ConfigNode is deactivated. 
2024-09-11 12:56:25,759 [Thread-0] INFO  o.a.i.c.s.ConfigNodeShutdownHook:49 - ConfigNode exiting... 
Exception in thread "Thread-0" java.lang.NullPointerException
    at org.apache.iotdb.confignode.service.ConfigNodeShutdownHook.run(ConfigNodeShutdownHook.java:51)

What did you expect to see?

Pod starting

What did you see instead?

Pod crashing with error "CrashLoopBackOff"

Anything else?

No response

Are you willing to submit a PR?

[ ] I'm willing to submit a PR!

github-actions[bot] commented 2 months ago

Hi, this is your first issue in IoTDB project. Thanks for your report. Welcome to join the community!

HTHou commented 2 months ago

@CritasWang do you have any clue about it?

gzigurella commented 2 months ago

Following the issue, facing the issue on OKD as well.

Tried on OKD (3 nodes on CentOS) and on a single-node K3S cluster on a Fedora 39, the latter is not experiencing the problem therefore I am guessing it could be a problem related to Network File System? Since it's the only notable difference I am facing between the two environments

edit: typo

CritasWang commented 2 months ago

What is the method of storage usage. Perhaps we can consider mounting the directory for. We did not encounter this situation in both k8s and k3s

180Gio commented 2 months ago

I have a GPFS based on IBM Spectrum Scale, I don't know if I can handle it using mount because PVC and PV are handled by IBM Spectrum Scale. The drives are configured in RAID 3

CritasWang commented 2 months ago

Perhaps you can try manually creating the corresponding directory in PVC

SeanGaluzzi commented 1 month ago

@CritasWang, you mentioned k8s. I am trying to create a 2C2D cluster, but I'm encountering some issues. Only one node initializes, while the other one are stuck in a crash loop. Could you provide YAML files for a basic configuration?

So far, I've created files for the service, one for the PV and PVC, one for the config map (which I'm not too sure about), and two for the config node and data node.

SVC

apiVersion: v1
kind: Service
metadata:
  name: iotdb-confignode
  namespace: custom-iotdb-cluster
spec:
  selector:
    app: iotdb-confignode
  ports:
    - name: rpc-port
      port: 10710
      targetPort: 10710
    - name: consensus-port
      port: 10720
      targetPort: 10720
  clusterIP: None  # Necessario per garantire l'indirizzamento stabile con StatefulSet
---

apiVersion: v1
kind: Service
metadata:
  name: iotdb-datanode
  namespace: custom-iotdb-cluster
spec:
  selector:
    app: iotdb-datanode
  ports:
    - name: rpc-port
      port: 6667
      targetPort: 6667
    - name: internal-port
      port: 10710
      targetPort: 10710
    - name: schema-region-consensus-port
      port: 10750
      targetPort: 10750
    - name: data-region-consensus-port
      port: 10760
      targetPort: 10760
  clusterIP: None  # Necessario per garantire l'indirizzamento stabile con StatefulSet

PVC-PV

apiVersion: v1
kind: PersistentVolume
metadata:
  name: iotdb-confignode-pv
  namespace: custom-iotdb-cluster
spec:
  capacity:
    storage: 10Gi
  accessModes:
    - ReadWriteOnce
  hostPath:
    path: /data/iotdb/confignode
---
apiVersion: v1
kind: PersistentVolume
metadata:
  name: iotdb-datanode-pv
  namespace: custom-iotdb-cluster
spec:
  capacity:
    storage: 10Gi
  accessModes:
    - ReadWriteOnce
  hostPath:
    path: /data/iotdb/datanode
---
apiVersion: v1
kind: PersistentVolumeClaim
metadata:
  name: iotdb-confignode-pvc
  namespace: custom-iotdb-cluster
spec:
  accessModes:
    - ReadWriteOnce
  resources:
    requests:
      storage: 10Gi
---
apiVersion: v1
kind: PersistentVolumeClaim
metadata:
  name: iotdb-datanode-pvc
  namespace: custom-iotdb-cluster
spec:
  accessModes:
    - ReadWriteOnce
  resources:
    requests:
      storage: 10Gi

Configmap

apiVersion: v1
kind: ConfigMap
metadata:
  name: iotdb-configmap
  namespace: custom-iotdb-cluster
data:
  iotdb-datanode.properties: |
    # Configurazioni per il datanode
    dn_rpc_address=iotdb-datanode-0.iotdb-datanode.custom-iotdb-cluster.svc.cluster.local
    dn_rpc_port=6667
    dn_internal_address=iotdb-datanode-0
    dn_internal_port=10710
    dn_schema_region_consensus_port=10750
    dn_data_region_consensus_port=10760
    data_replication_factor=2

    # Specifica del confignode seed per il datanode
    dn_seed_config_node=iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10710

  iotdb-confignode.properties: |
    # Configurazioni per il confignode
    cn_internal_address=iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local
    cn_internal_port=10710
    cn_consensus_port=10720
    schema_replication_factor=2

    # Specifica del seed config node per il confignode
    cn_seed_config_node=iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10710

Confignode

apiVersion: apps/v1
kind: StatefulSet
metadata:
  name: iotdb-confignode
  namespace: custom-iotdb-cluster
spec:
  serviceName: "iotdb-confignode"
  replicas: 2
  selector:
    matchLabels:
      app: iotdb-confignode
  template:
    metadata:
      labels:
        app: iotdb-confignode
    spec:
      containers:
        - name: iotdb-confignode
          image: apache/iotdb:1.3.2-confignode
          env:
            - name: CONFIG_NODE_INTERNAL_ADDRESS
              valueFrom:
                fieldRef:
                  fieldPath: metadata.name
          volumeMounts:
            - name: confignode-data
              mountPath: /iotdb/data
            - name: config-volume
              mountPath: /iotdb/conf/iotdb-confignode.properties
              subPath: iotdb-confignode.properties
      volumes:
        - name: config-volume
          configMap:
            name: iotdb-configmap
  volumeClaimTemplates:
    - metadata:
        name: confignode-data
      spec:
        accessModes: ["ReadWriteOnce"]
        resources:
          requests:
            storage: 10Gi

Datanode

apiVersion: apps/v1
kind: StatefulSet
metadata:
  name: iotdb-datanode
  namespace: custom-iotdb-cluster
spec:
  serviceName: "iotdb-datanode"
  replicas: 2
  selector:
    matchLabels:
      app: iotdb-datanode
  template:
    metadata:
      labels:
        app: iotdb-datanode
    spec:
      containers:
        - name: iotdb-datanode
          image: apache/iotdb:1.3.2-datanode
          env:
            - name: DATA_NODE_INTERNAL_ADDRESS
              valueFrom:
                fieldRef:
                  fieldPath: metadata.name
          volumeMounts:
            - name: datanode-data
              mountPath: /iotdb/data
            - name: config-volume
              mountPath: /iotdb/conf/iotdb-datanode.properties
              subPath: iotdb-datanode.properties
      volumes:
        - name: config-volume
          configMap:
            name: iotdb-configmap
  volumeClaimTemplates:
    - metadata:
        name: datanode-data
      spec:
        accessModes: ["ReadWriteOnce"]
        resources:
          requests:
            storage: 10Gi

kubectl get all output

root@kubemaster:/home/kubemaster/k8s_iotdb_cluster/newconf# kubectl get all
NAME                     READY   STATUS             RESTARTS        AGE
pod/iotdb-confignode-0   1/1     Running            0               9m41s
pod/iotdb-confignode-1   0/1     CrashLoopBackOff   6 (2m42s ago)   9m32s
pod/iotdb-datanode-0     1/1     Running            0               9m15s
pod/iotdb-datanode-1     0/1     CrashLoopBackOff   6 (2m3s ago)    9m7s

NAME                       TYPE        CLUSTER-IP   EXTERNAL-IP   PORT(S)                                  AGE
service/iotdb-confignode   ClusterIP   None         <none>        10710/TCP,10720/TCP                      9m50s
service/iotdb-datanode     ClusterIP   None         <none>        6667/TCP,10710/TCP,10750/TCP,10760/TCP   9m50s

NAME                                READY   AGE
statefulset.apps/iotdb-confignode   1/2     9m41s
statefulset.apps/iotdb-datanode     1/2     9m15s

kubectl logs pod/iotdb-confignode-1

----------------------------
Starting IoTDB ConfigNode
----------------------------
Checking whether the ports are already occupied...
WARN:
WARN: the value of net.core.somaxconn (=4096) is too small, please set it to a larger value using the following command.
WARN:     sudo sysctl -w net.core.somaxconn=65535
WARN: The original net.core.somaxconn value will be set back when the os reboots.
WARN:
setting local JMX...
ConfigNode on heap memory size = 1785MB, off heap memory size = 597MB
If you want to change this configuration, please check conf/confignode-env.sh.
2024-10-15 15:11:22,063 [main] INFO  o.a.i.c.c.ConfigNodeDescriptor:109 - Start to read config file file:/iotdb/sbin/../conf/iotdb-common.properties
2024-10-15 15:11:22,081 [main] INFO  o.a.i.c.c.ConfigNodeDescriptor:131 - start reading ConfigNode conf file: file:/iotdb/sbin/../conf/iotdb-confignode.properties
2024-10-15 15:11:22,167 [main] INFO  o.a.i.c.s.ConfigNode:108 - IoTDB-ConfigNode environment variables:
        CONFIGNODE_HOME=/iotdb/sbin/..;
        CONFIGNODE_CONF=/iotdb/sbin/../conf;
2024-10-15 15:11:22,168 [main] INFO  o.a.i.c.s.ConfigNode:112 - IoTDB-ConfigNode default charset is: UTF-8
2024-10-15 15:11:22,172 [main] INFO  o.a.i.c.s.ConfigNodeCommandLine:68 - Running mode -s
2024-10-15 15:11:22,173 [main] INFO  o.a.i.c.s.ConfigNodeCommandLine:72 - Starting IoTDB 1.3.2 (Build: aa0ff4a)
2024-10-15 15:11:22,180 [main] INFO  o.a.i.c.c.ConfigNodeStartupCheck:65 - configNode port check successful.
2024-10-15 15:11:22,184 [main] INFO  o.a.i.c.s.StartupChecks:50 - Start JMX locally.
2024-10-15 15:11:22,186 [main] INFO  o.a.i.c.s.StartupChecks:78 - JDK version is 11.
2024-10-15 15:11:22,187 [main] INFO  o.a.i.c.s.StartupChecks:84 - JVM version is OpenJDK 64-Bit Server VM 11.0.24+8.
2024-10-15 15:11:22,205 [main] INFO  o.a.i.c.s.ConfigNode:120 - Activating IoTDB-ConfigNode...
2024-10-15 15:11:22,208 [main] INFO  o.a.i.c.s.RegisterManager:54 - The JMX ServerService service is started successfully, which takes 0 ms.
2024-10-15 15:11:22,422 [main] INFO  o.a.i.c.p.c.PipeConfig:271 - PipeHardlinkBaseDirName: pipe
2024-10-15 15:11:22,422 [main] INFO  o.a.i.c.p.c.PipeConfig:272 - PipeHardlinkTsFileDirName: tsfile
2024-10-15 15:11:22,422 [main] INFO  o.a.i.c.p.c.PipeConfig:273 - PipeHardlinkWALDirName: wal
2024-10-15 15:11:22,423 [main] INFO  o.a.i.c.p.c.PipeConfig:274 - PipeHardLinkWALEnabled: false
2024-10-15 15:11:22,423 [main] INFO  o.a.i.c.p.c.PipeConfig:276 - PipeDataStructureTabletRowSize: 2048
2024-10-15 15:11:22,423 [main] INFO  o.a.i.c.p.c.PipeConfig:277 - PipeDataStructureTabletMemoryBlockAllocationRejectThreshold: 0.4
2024-10-15 15:11:22,424 [main] INFO  o.a.i.c.p.c.PipeConfig:281 - PipeSubtaskExecutorMaxThreadNum: 2
2024-10-15 15:11:22,424 [main] INFO  o.a.i.c.p.c.PipeConfig:282 - PipeSubtaskExecutorBasicCheckPointIntervalByConsumedEventCount: 10000
2024-10-15 15:11:22,424 [main] INFO  o.a.i.c.p.c.PipeConfig:285 - PipeSubtaskExecutorBasicCheckPointIntervalByTimeDuration: 10000
2024-10-15 15:11:22,424 [main] INFO  o.a.i.c.p.c.PipeConfig:288 - PipeSubtaskExecutorPendingQueueMaxBlockingTimeMs: 1000
2024-10-15 15:11:22,424 [main] INFO  o.a.i.c.p.c.PipeConfig:291 - PipeSubtaskExecutorCronHeartbeatEventIntervalSeconds: 20
2024-10-15 15:11:22,425 [main] INFO  o.a.i.c.p.c.PipeConfig:295 - PipeExtractorAssignerDisruptorRingBufferSize: 65536
2024-10-15 15:11:22,425 [main] INFO  o.a.i.c.p.c.PipeConfig:298 - PipeExtractorAssignerDisruptorRingBufferEntrySizeInBytes: 50
2024-10-15 15:11:22,425 [main] INFO  o.a.i.c.p.c.PipeConfig:301 - PipeExtractorMatcherCacheSize: 1024
2024-10-15 15:11:22,425 [main] INFO  o.a.i.c.p.c.PipeConfig:303 - PipeConnectorHandshakeTimeoutMs: 10000
2024-10-15 15:11:22,426 [main] INFO  o.a.i.c.p.c.PipeConfig:304 - PipeConnectorTransferTimeoutMs: 900000
2024-10-15 15:11:22,426 [main] INFO  o.a.i.c.p.c.PipeConfig:305 - PipeConnectorReadFileBufferSize: 8388608
2024-10-15 15:11:22,426 [main] INFO  o.a.i.c.p.c.PipeConfig:306 - PipeConnectorRetryIntervalMs: 1000
2024-10-15 15:11:22,426 [main] INFO  o.a.i.c.p.c.PipeConfig:307 - PipeConnectorPendingQueueSize: 256
2024-10-15 15:11:22,426 [main] INFO  o.a.i.c.p.c.PipeConfig:308 - PipeConnectorRPCThriftCompressionEnabled: false
2024-10-15 15:11:22,427 [main] INFO  o.a.i.c.p.c.PipeConfig:311 - PipeLeaderCacheMemoryUsagePercentage: 0.1
2024-10-15 15:11:22,427 [main] INFO  o.a.i.c.p.c.PipeConfig:313 - PipeListeningQueueTransferSnapshotThreshold: 1000
2024-10-15 15:11:22,427 [main] INFO  o.a.i.c.p.c.PipeConfig:316 - PipeSnapshotExecutionMaxBatchSize: 1000
2024-10-15 15:11:22,427 [main] INFO  o.a.i.c.p.c.PipeConfig:318 - PipeAsyncConnectorSelectorNumber: 4
2024-10-15 15:11:22,428 [main] INFO  o.a.i.c.p.c.PipeConfig:319 - PipeAsyncConnectorMaxClientNumber: 16
2024-10-15 15:11:22,428 [main] INFO  o.a.i.c.p.c.PipeConfig:321 - SeperatedPipeHeartbeatEnabled: true
2024-10-15 15:11:22,428 [main] INFO  o.a.i.c.p.c.PipeConfig:322 - PipeHeartbeatIntervalSecondsForCollectingPipeMeta: 100
2024-10-15 15:11:22,428 [main] INFO  o.a.i.c.p.c.PipeConfig:325 - PipeMetaSyncerInitialSyncDelayMinutes: 3
2024-10-15 15:11:22,429 [main] INFO  o.a.i.c.p.c.PipeConfig:327 - PipeMetaSyncerSyncIntervalMinutes: 3
2024-10-15 15:11:22,429 [main] INFO  o.a.i.c.p.c.PipeConfig:328 - PipeMetaSyncerAutoRestartPipeCheckIntervalRound: 1
2024-10-15 15:11:22,429 [main] INFO  o.a.i.c.p.c.PipeConfig:331 - PipeAutoRestartEnabled: true
2024-10-15 15:11:22,429 [main] INFO  o.a.i.c.p.c.PipeConfig:333 - PipeAirGapReceiverEnabled: false
2024-10-15 15:11:22,429 [main] INFO  o.a.i.c.p.c.PipeConfig:334 - PipeAirGapReceiverPort: 9780
2024-10-15 15:11:22,430 [main] INFO  o.a.i.c.p.c.PipeConfig:336 - PipeMaxAllowedHistoricalTsFilePerDataRegion: 100
2024-10-15 15:11:22,430 [main] INFO  o.a.i.c.p.c.PipeConfig:339 - PipeMaxAllowedPendingTsFileEpochPerDataRegion: 2
2024-10-15 15:11:22,430 [main] INFO  o.a.i.c.p.c.PipeConfig:342 - PipeMaxAllowedPinnedMemTableCount: 50
2024-10-15 15:11:22,430 [main] INFO  o.a.i.c.p.c.PipeConfig:343 - PipeMaxAllowedLinkedTsFileCount: 100
2024-10-15 15:11:22,431 [main] INFO  o.a.i.c.p.c.PipeConfig:344 - PipeStuckRestartIntervalSeconds: 120
2024-10-15 15:11:22,431 [main] INFO  o.a.i.c.p.c.PipeConfig:346 - PipeMetaReportMaxLogNumPerRound: 10
2024-10-15 15:11:22,431 [main] INFO  o.a.i.c.p.c.PipeConfig:347 - PipeMetaReportMaxLogIntervalRounds: 36
2024-10-15 15:11:22,431 [main] INFO  o.a.i.c.p.c.PipeConfig:348 - PipeTsFilePinMaxLogNumPerRound: 10
2024-10-15 15:11:22,431 [main] INFO  o.a.i.c.p.c.PipeConfig:349 - PipeTsFilePinMaxLogIntervalRounds: 90
2024-10-15 15:11:22,432 [main] INFO  o.a.i.c.p.c.PipeConfig:350 - PipeWalPinMaxLogNumPerRound: 10
2024-10-15 15:11:22,432 [main] INFO  o.a.i.c.p.c.PipeConfig:351 - PipeWalPinMaxLogIntervalRounds: 90
2024-10-15 15:11:22,432 [main] INFO  o.a.i.c.p.c.PipeConfig:353 - PipeMemoryManagementEnabled: true
2024-10-15 15:11:22,432 [main] INFO  o.a.i.c.p.c.PipeConfig:354 - PipeMemoryAllocateMaxRetries: 10
2024-10-15 15:11:22,432 [main] INFO  o.a.i.c.p.c.PipeConfig:355 - PipeMemoryAllocateRetryIntervalInMs: 1000
2024-10-15 15:11:22,432 [main] INFO  o.a.i.c.p.c.PipeConfig:357 - PipeMemoryAllocateMinSizeInBytes: 32
2024-10-15 15:11:22,433 [main] INFO  o.a.i.c.p.c.PipeConfig:358 - PipeMemoryAllocateForTsFileSequenceReaderInBytes: 2097152
2024-10-15 15:11:22,433 [main] INFO  o.a.i.c.p.c.PipeConfig:361 - PipeMemoryExpanderIntervalSeconds: 180
2024-10-15 15:11:22,433 [main] INFO  o.a.i.c.p.c.PipeConfig:363 - TwoStageAggregateMaxCombinerLiveTimeInMs: 480000
2024-10-15 15:11:22,433 [main] INFO  o.a.i.c.p.c.PipeConfig:366 - TwoStageAggregateDataRegionInfoCacheTimeInMs: 180000
2024-10-15 15:11:22,434 [main] INFO  o.a.i.c.p.c.PipeConfig:369 - TwoStageAggregateSenderEndPointsCacheInMs: 180000
2024-10-15 15:11:22,448 [main] INFO  o.a.i.c.p.r.IoTDBReceiverAgent:118 - Clean pipe receiver dir /iotdb/sbin/../data/confignode/system/pipe/receiver successfully.
2024-10-15 15:11:22,448 [main] INFO  o.a.i.c.p.r.IoTDBReceiverAgent:125 - Create pipe receiver dir /iotdb/sbin/../data/confignode/system/pipe/receiver successfully.
2024-10-15 15:11:22,449 [main] INFO  o.a.i.c.m.p.a.r.PipeConfigNodeRuntimeAgent:63 - PipeRuntimeConfigNodeAgent started
2024-10-15 15:11:22,449 [main] INFO  o.a.i.c.s.RegisterManager:54 - The Pipe Runtime Config Node Agent service is started successfully, which takes 29 ms.
2024-10-15 15:11:22,449 [main] INFO  o.a.i.c.s.ConfigNode:256 - Successfully setup internal services.
2024-10-15 15:11:22,484 [main] INFO  o.a.i.c.a.a.BasicAuthorizer$InstanceHolder:104 - Authorizer provider class: org.apache.iotdb.commons.auth.authorizer.LocalFileAuthorizer
2024-10-15 15:11:22,585 [main] INFO  o.a.i.c.a.u.BasicUserManager:130 - Admin initialized
2024-10-15 15:11:22,685 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:170 - new cached thread pool: ConfigNode-Manager-Recovery
2024-10-15 15:11:22,719 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: IoTDB-Region-Maintainer
2024-10-15 15:11:22,786 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:233 - new scheduled thread pool: CQ-Scheduler
2024-10-15 15:11:22,795 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:137 - new single thread pool: Pipe-Runtime-Procedure-Submitter
2024-10-15 15:11:22,799 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: Pipe-Runtime-Meta-Syncer
2024-10-15 15:11:22,801 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: Pipe-Runtime-Heartbeat
2024-10-15 15:11:22,806 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: Subscription-Runtime-Meta-Syncer
2024-10-15 15:11:22,822 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: Cluster-Heartbeat-Service
2024-10-15 15:11:22,823 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: Cluster-LoadStatistics-Service
2024-10-15 15:11:22,827 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: Cluster-Event-Service
2024-10-15 15:11:22,829 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:71 - new fixed thread pool: Cluster-LoadStatistics-Publisher, thread number: 5
2024-10-15 15:11:22,960 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: Cluster-RetryFailedTasks-Service
2024-10-15 15:11:22,964 [main] INFO  o.a.i.c.s.ConfigNode:307 - Successfully initialize ConfigManager.
2024-10-15 15:11:22,964 [main] INFO  o.a.i.c.s.ConfigNode:133 - IoTDB-ConfigNode is in restarting process...
2024-10-15 15:11:23,177 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: RatisBgDiskGuardian
2024-10-15 15:11:23,290 [main] INFO  o.a.r.m.MetricRegistriesLoader:64 - Loaded MetricRegistries class org.apache.iotdb.consensus.ratis.metrics.MetricRegistryManager
2024-10-15 15:11:23,311 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.rpc.type = GRPC (default)
2024-10-15 15:11:23,317 [main] INFO  o.a.ratis.conf.ConfUtils:53 - raft.grpc.admin.host = null (fallback to raft.grpc.server.host)
2024-10-15 15:11:23,319 [main] INFO  o.a.ratis.conf.ConfUtils:53 - raft.grpc.admin.port = 10720 (fallback to raft.grpc.server.port)
2024-10-15 15:11:23,320 [main] INFO  o.a.ratis.conf.ConfUtils:53 - raft.grpc.client.host = null (fallback to raft.grpc.server.host)
2024-10-15 15:11:23,321 [main] INFO  o.a.ratis.conf.ConfUtils:53 - raft.grpc.client.port = 10720 (fallback to raft.grpc.server.port)
2024-10-15 15:11:23,322 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.grpc.server.host = null (default)
2024-10-15 15:11:23,323 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.grpc.server.port = 10720 (custom)
2024-10-15 15:11:23,323 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.grpc.message.size.max = 512MB (=536870912) (custom)
2024-10-15 15:11:23,324 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.appender.buffer.byte-limit = 16777216 (custom)
2024-10-15 15:11:23,325 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.grpc.flow.control.window = 4194304 (custom)
2024-10-15 15:11:23,326 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.request.timeout = 10000ms (custom)
2024-10-15 15:11:23,339 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.grpc.server.heartbeat.channel = true (default)
2024-10-15 15:11:23,343 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.grpc.server.async.request.thread.pool.cached = true (default)
2024-10-15 15:11:23,343 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.grpc.server.async.request.thread.pool.size = 32 (default)
2024-10-15 15:11:23,667 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.datastream.type = DISABLED (default)
2024-10-15 15:11:23,670 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.sleep.deviation.threshold = 4000ms (custom)
2024-10-15 15:11:23,671 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.close.threshold = 2147483647s (custom)
2024-10-15 15:11:23,673 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.leaderelection.leader.step-down.wait-time = 30s (custom)
2024-10-15 15:11:23,687 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.storage.dir = [/iotdb/sbin/../data/confignode/consensus] (custom)
2024-10-15 15:11:23,689 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.threadpool.proxy.cached = true (default)
2024-10-15 15:11:23,690 [main] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.threadpool.proxy.size = 0 (default)
2024-10-15 15:11:23,700 [0-impl-thread1] INFO  o.a.r.s.i.RaftServerProxy:266 - 0: found a subdirectory /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000
2024-10-15 15:11:23,741 [0-impl-thread1] INFO  o.a.r.s.i.RaftServerProxy$ImplMap:101 - 0: addNew group-000000000000:[] returns group-000000000000:java.util.concurrent.CompletableFuture@485c879e[Not completed]
2024-10-15 15:11:23,795 [0-groupManagement] INFO  o.a.r.s.i.RaftServerImpl:253 - 0: new RaftServerImpl for group-000000000000:[] with ApplicationStateMachineProxy:uninitialized
2024-10-15 15:11:23,800 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.timeout.min = 2000ms (custom)
2024-10-15 15:11:23,801 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.timeout.max = 4000ms (custom)
2024-10-15 15:11:23,802 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.sleep.time = 1s (custom)
2024-10-15 15:11:23,803 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.slowness.timeout = 60000ms (default)
2024-10-15 15:11:23,804 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.leaderelection.leader.step-down.wait-time = 30s (custom)
2024-10-15 15:11:23,805 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.leaderelection.member.majority-add = false (default)
2024-10-15 15:11:23,806 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.sleep.deviation.threshold = 4000ms (custom)
2024-10-15 15:11:23,820 [0-groupManagement] INFO  o.a.r.s.impl.ServerState:114 - 0@group-000000000000: ConfigurationManager, init=conf: {index: -1, cur=peers:[]|listeners:[], old=null}, confs=<EMPTY_MAP>
2024-10-15 15:11:23,832 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.notification.no-leader.timeout = 60s (default)
2024-10-15 15:11:23,837 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.read.timeout = 60000ms (custom)
2024-10-15 15:11:23,844 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.retrycache.expirytime = 142700ms (custom)
2024-10-15 15:11:23,845 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.retrycache.statistics.expirytime = 100ms (default)
2024-10-15 15:11:23,854 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.read.option = LINEARIZABLE (custom)
2024-10-15 15:11:23,856 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.read.read-after-write-consistent.write-index-cache.expiry-time = 60s (default)
2024-10-15 15:11:23,899 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.request.timeout = 10000ms (custom)
2024-10-15 15:11:23,905 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.appender.install.snapshot.enabled = true (default)
2024-10-15 15:11:23,906 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.threadpool.server.cached = true (default)
2024-10-15 15:11:23,907 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.threadpool.server.size = 0 (default)
2024-10-15 15:11:23,908 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.threadpool.client.cached = true (default)
2024-10-15 15:11:23,909 [0-groupManagement] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.threadpool.client.size = 0 (default)
2024-10-15 15:11:23,913 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.storage.free-space.min = 0MB (=0) (default)
2024-10-15 15:11:23,915 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.corruption.policy = WARN_AND_RETURN (custom)
2024-10-15 15:11:23,916 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.storage.dir = [/iotdb/sbin/../data/confignode/consensus] (custom)
2024-10-15 15:11:24,027 [0-impl-thread1] INFO  o.a.r.s.s.RaftStorageDirectoryImpl:229 - Lock on /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/in_use.lock acquired by nodename 7@iotdb-confignode-1
2024-10-15 15:11:24,042 [0-impl-thread1] INFO  o.a.r.s.s.RaftStorageImpl:118 - Read RaftStorageMetadata{term=6, votedFor=0} from /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/raft-meta
2024-10-15 15:11:24,105 [0-impl-thread1] INFO  o.a.r.s.impl.ServerState:386 - 0@group-000000000000: set configuration conf: {index: 15, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,116 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.use.memory = false (default)
2024-10-15 15:11:24,134 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.purge.gap = 1024 (default)
2024-10-15 15:11:24,135 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.appender.buffer.byte-limit = 16777216 (custom)
2024-10-15 15:11:24,139 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.statemachine.data.read.timeout = 1000ms (default)
2024-10-15 15:11:24,140 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.purge.preservation.log.num = 1000 (custom)
2024-10-15 15:11:24,146 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.segment.size.max = 24MB (=25165824) (custom)
2024-10-15 15:11:24,155 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.segment.cache.num.max = 2 (custom)
2024-10-15 15:11:24,157 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.segment.cache.size.max = 25165824 (custom)
2024-10-15 15:11:24,157 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.appender.buffer.byte-limit = 16777216 (custom)
2024-10-15 15:11:24,162 [0-impl-thread1] INFO  o.a.ratis.util.AwaitToRun:81 - Thread[0@group-000000000000-cacheEviction-AwaitToRun,5,main] started
2024-10-15 15:11:24,173 [0-impl-thread1] INFO  o.a.r.s.r.s.SegmentedRaftLogWorker:184 - new 0@group-000000000000-SegmentedRaftLogWorker for RaftStorageImpl:Storage Directory /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000
2024-10-15 15:11:24,174 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.queue.byte-limit = 64MB (=67108864) (custom)
2024-10-15 15:11:24,175 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.queue.element-limit = 4096 (default)
2024-10-15 15:11:24,180 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.segment.size.max = 24MB (=25165824) (custom)
2024-10-15 15:11:24,181 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.preallocated.size = 4MB (=4194304) (custom)
2024-10-15 15:11:24,182 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.force.sync.num = 128 (default)
2024-10-15 15:11:24,184 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.statemachine.data.sync = true (default)
2024-10-15 15:11:24,184 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.statemachine.data.sync.timeout = 10s (default)
2024-10-15 15:11:24,185 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.statemachine.data.sync.timeout.retry = -1 (default)
2024-10-15 15:11:24,188 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.write.buffer.size = 16777224 (custom)
2024-10-15 15:11:24,235 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.appender.buffer.byte-limit = 16777216 (custom)
2024-10-15 15:11:24,237 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.unsafe-flush.enabled = false (default)
2024-10-15 15:11:24,238 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.async-flush.enabled = false (default)
2024-10-15 15:11:24,238 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.statemachine.data.caching.enabled = false (default)
2024-10-15 15:11:24,277 [0-impl-thread1] INFO  o.a.r.s.impl.ServerState:386 - 0@group-000000000000: set configuration conf: {index: 0, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,284 [0-impl-thread1] INFO  o.a.r.s.r.s.LogSegment:175 - Successfully read 7 entries from segment file /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_0-6
2024-10-15 15:11:24,289 [0-impl-thread1] INFO  o.a.r.s.impl.ServerState:386 - 0@group-000000000000: set configuration conf: {index: 7, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,289 [0-impl-thread1] INFO  o.a.r.s.r.s.LogSegment:175 - Successfully read 2 entries from segment file /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_7-8
2024-10-15 15:11:24,291 [0-impl-thread1] INFO  o.a.r.s.impl.ServerState:386 - 0@group-000000000000: set configuration conf: {index: 9, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,291 [0-impl-thread1] INFO  o.a.r.s.r.s.LogSegment:175 - Successfully read 2 entries from segment file /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_9-10
2024-10-15 15:11:24,292 [0-impl-thread1] INFO  o.a.r.s.impl.ServerState:386 - 0@group-000000000000: set configuration conf: {index: 11, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,292 [0-impl-thread1] INFO  o.a.r.s.r.s.LogSegment:175 - Successfully read 2 entries from segment file /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_11-12
2024-10-15 15:11:24,293 [0-impl-thread1] INFO  o.a.r.s.impl.ServerState:386 - 0@group-000000000000: set configuration conf: {index: 13, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,294 [0-impl-thread1] INFO  o.a.r.s.r.s.LogSegment:175 - Successfully read 2 entries from segment file /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_13-14
2024-10-15 15:11:24,295 [0-impl-thread1] INFO  o.a.r.s.impl.ServerState:386 - 0@group-000000000000: set configuration conf: {index: 15, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,374 [0-impl-thread1] INFO  o.a.r.s.r.s.LogSegment:175 - Successfully read 2 entries from segment file /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_inprogress_15
2024-10-15 15:11:24,379 [0-impl-thread1] INFO  o.a.r.s.r.s.SegmentedRaftLogWorker:135 - 0@group-000000000000-SegmentedRaftLogWorker: flushIndex: setUnconditionally 0 -> 16
2024-10-15 15:11:24,379 [0-impl-thread1] INFO  o.a.r.s.r.s.SegmentedRaftLogWorker:135 - 0@group-000000000000-SegmentedRaftLogWorker: safeCacheEvictIndex: setUnconditionally 0 -> -1
2024-10-15 15:11:24,414 [0-impl-thread1] INFO  o.a.r.s.r.s.BufferedWriteChannel:61 - open log_inprogress_15 (append) at position 121
2024-10-15 15:11:24,418 [0-impl-thread1] INFO  o.a.r.s.r.RaftLogBase:54 - 0@group-000000000000-SegmentedRaftLog: commitIndex: updateToMax old=-1, new=15, updated? true
2024-10-15 15:11:24,418 [0-impl-thread1] INFO  o.a.r.s.i.RaftServerImpl:389 - 0@group-000000000000: start as a follower, conf=conf: {index: 15, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,418 [0-impl-thread1] INFO  o.a.r.s.i.RaftServerImpl:376 - 0@group-000000000000: changes role from      null to FOLLOWER at term 6 for startAsFollower
2024-10-15 15:11:24,422 [0-impl-thread1] INFO  o.a.r.s.impl.RoleInfo:148 - 0: start 0@group-000000000000-FollowerState
2024-10-15 15:11:24,424 [0@group-000000000000-FollowerState] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.first-election.timeout.min = 50ms (custom)
2024-10-15 15:11:24,428 [0@group-000000000000-FollowerState] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.first-election.timeout.max = 150ms (custom)
2024-10-15 15:11:24,433 [0-impl-thread1] INFO  o.a.r.util.JmxRegister:44 - Successfully registered JMX Bean with object name Ratis:service=RaftServer,group=group-000000000000,id=0
2024-10-15 15:11:24,433 [0-impl-thread1] INFO  o.a.r.util.JmxRegister:58 - register mxBean class org.apache.ratis.server.impl.RaftServerJmxAdapter as Ratis:service=RaftServer,group=group-000000000000,id=0
2024-10-15 15:11:24,438 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.snapshot.trigger-when-stop.enabled = true (default)
2024-10-15 15:11:24,439 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.snapshot.trigger-when-remove.enabled = false (custom)
2024-10-15 15:11:24,440 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.snapshot.auto.trigger.enabled = true (custom)
2024-10-15 15:11:24,440 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.snapshot.auto.trigger.threshold = 400000 (default)
2024-10-15 15:11:24,441 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.snapshot.retention.file.num = 2 (custom)
2024-10-15 15:11:24,443 [0-impl-thread1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.purge.upto.snapshot.index = true (custom)
2024-10-15 15:11:24,451 [main] INFO  o.a.r.s.i.RaftServerProxy:408 - 0: start RPC server
2024-10-15 15:11:24,501 [0@group-000000000000-FollowerState] INFO  o.a.r.s.i.FollowerState:144 - 0@group-000000000000-FollowerState: change to CANDIDATE, lastRpcElapsedTime:79784003ns, electionTimeout:66ms
2024-10-15 15:11:24,502 [0@group-000000000000-FollowerState] INFO  o.a.r.s.impl.RoleInfo:119 - 0: shutdown 0@group-000000000000-FollowerState
2024-10-15 15:11:24,503 [0@group-000000000000-FollowerState] INFO  o.a.r.s.i.RaftServerImpl:376 - 0@group-000000000000: changes role from  FOLLOWER to CANDIDATE at term 6 for changeToCandidate
2024-10-15 15:11:24,510 [0@group-000000000000-FollowerState] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.leaderelection.pre-vote = true (default)
2024-10-15 15:11:24,510 [0@group-000000000000-FollowerState] INFO  o.a.r.s.impl.RoleInfo:148 - 0: start 0@group-000000000000-LeaderElection1
2024-10-15 15:11:24,517 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.i.LeaderElection:321 - 0@group-000000000000-LeaderElection1 PRE_VOTE round 0: submit vote requests at term 6 for conf: {index: 15, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,522 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.i.LeaderElection:323 - 0@group-000000000000-LeaderElection1 PRE_VOTE round 0: result PASSED (term=6)
2024-10-15 15:11:24,579 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.i.LeaderElection:321 - 0@group-000000000000-LeaderElection1 ELECTION round 0: submit vote requests at term 7 for conf: {index: 15, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,579 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.i.LeaderElection:323 - 0@group-000000000000-LeaderElection1 ELECTION round 0: result PASSED (term=7)
2024-10-15 15:11:24,580 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.impl.RoleInfo:139 - 0: shutdown 0@group-000000000000-LeaderElection1
2024-10-15 15:11:24,581 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.i.RaftServerImpl:376 - 0@group-000000000000: changes role from CANDIDATE to LEADER at term 7 for changeToLeader
2024-10-15 15:11:24,607 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.staging.catchup.gap = 1000 (default)
2024-10-15 15:11:24,608 [main] INFO  o.a.r.g.s.GrpcService:302 - 0: GrpcService started, listening on 10720
2024-10-15 15:11:24,614 [JvmPauseMonitor0] INFO  o.a.r.u.JvmPauseMonitor:146 - JvmPauseMonitor-0: Started
2024-10-15 15:11:24,626 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.write.element-limit = 4096 (default)
2024-10-15 15:11:24,629 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.write.byte-limit = 64MB (=67108864) (default)
2024-10-15 15:11:24,634 [main] INFO  o.a.i.c.m.c.ConsensusManager:89 - Init ConsensusManager successfully when restarted
2024-10-15 15:11:24,639 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.watch.timeout = 10s (default)
2024-10-15 15:11:24,640 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.watch.timeout.denomination = 1s (default)
2024-10-15 15:11:24,646 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.watch.element-limit = 65536 (default)
2024-10-15 15:11:24,668 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.read.leader.lease.enabled = false (default)
2024-10-15 15:11:24,673 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.read.leader.lease.timeout.ratio = 0.9 (default)
2024-10-15 15:11:24,674 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.rpc.timeout.min = 2000ms (custom)
2024-10-15 15:11:24,675 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.log.log-metadata.enabled = true (default)
2024-10-15 15:11:24,676 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.write.element-limit = 4096 (default)
2024-10-15 15:11:24,678 [0@group-000000000000-LeaderElection1] INFO  o.a.ratis.conf.ConfUtils:46 - raft.server.write.follower.gap.ratio.max = -1.0 (default)
2024-10-15 15:11:24,682 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.impl.RoleInfo:148 - 0: start 0@group-000000000000-LeaderStateImpl
2024-10-15 15:11:24,683 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.i.RaftServerImpl:549 - 0@group-000000000000: set firstElectionSinceStartup to false for becomeLeader
2024-10-15 15:11:24,685 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.impl.ServerState:272 - 0@group-000000000000: change Leader from null to 0 at term 7 for becomeLeader, leader elected after 851ms
2024-10-15 15:11:24,696 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.node.NodeInfo:342 - Successfully apply ConfigNode: TConfigNodeLocation(configNodeId:0, internalEndPoint:TEndPoint(ip:iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local, port:10710), consensusEndPoint:TEndPoint(ip:iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local, port:10720)). Current ConfigNodeGroup: {0=TConfigNodeLocation(configNodeId:0, internalEndPoint:TEndPoint(ip:iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local, port:10710), consensusEndPoint:TEndPoint(ip:iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local, port:10720))}
2024-10-15 15:11:24,712 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.r.s.SegmentedRaftLogWorker:438 - 0@group-000000000000-SegmentedRaftLogWorker: Rolling segment log-15_16 to index:16
2024-10-15 15:11:24,722 [0@group-000000000000-SegmentedRaftLogWorker] INFO  o.a.r.s.r.s.SegmentedRaftLogWorker$FinalizeLogSegment:594 - 0@group-000000000000-SegmentedRaftLogWorker: Rolled log segment from /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_inprogress_15 to /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_15-16
2024-10-15 15:11:24,728 [0@group-000000000000-LeaderElection1] INFO  o.a.r.s.impl.ServerState:386 - 0@group-000000000000: set configuration conf: {index: 17, cur=peers:[0|iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local:10720]|listeners:[], old=null}
2024-10-15 15:11:24,732 [0@group-000000000000-SegmentedRaftLogWorker] INFO  o.a.r.s.r.s.BufferedWriteChannel:61 - open log_inprogress_17 at position 0
2024-10-15 15:11:24,744 [main] INFO  o.a.i.c.s.m.MetricService:99 - MetricService start to init.
2024-10-15 15:11:24,746 [main] INFO  o.a.i.m.AbstractMetricService:93 - Start metric service at level: CORE
2024-10-15 15:11:24,758 [main] INFO  o.a.i.c.s.m.MetricService:61 - Load metric reporters, type: []
2024-10-15 15:11:24,779 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.ClusterInfo:53 - clusterID has been generated: 19f0ef96-0850-4b8e-a8ae-a59e4a5aafff
2024-10-15 15:11:24,785 [main] INFO  o.a.i.c.s.m.MetricService:102 - MetricService start successfully.
2024-10-15 15:11:24,785 [main] INFO  o.a.i.c.s.RegisterManager:54 - The Metrics ServerService service is started successfully, which takes 41 ms.
2024-10-15 15:11:24,794 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.node.NodeInfo:403 - Successfully update Node 0 's version.
2024-10-15 15:11:24,805 [0@group-000000000000-SegmentedRaftLogWorker] INFO  o.a.r.s.r.s.SegmentedRaftLogWorker$StartLogSegment:637 - 0@group-000000000000-SegmentedRaftLogWorker: created new log segment /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/current/log_inprogress_17
2024-10-15 15:11:24,839 [main] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:213 - new single scheduled thread pool: JVM-GC-Statistics-Monitor
2024-10-15 15:11:24,859 [main] INFO  o.a.i.t.c.c.TSFileDescriptor:128 - try loading iotdb-common.properties from /iotdb/sbin/../conf/iotdb-common.properties
2024-10-15 15:11:24,918 [main] INFO  o.a.i.c.s.ThriftService:110 - IoTDB: start Config Node service...
2024-10-15 15:11:24,982 [0@group-000000000000-StateMachineUpdater] INFO  o.a.r.s.i.LeaderStateImpl$StartupLogEntry:316 - Leader 0@group-000000000000-LeaderStateImpl is ready since appliedIndex == startIndex == 17
2024-10-15 15:11:24,983 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.c.s.ConfigRegionStateMachine:281 - Current node [nodeId: 0, ip:port: TEndPoint(ip:iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local, port:10720)] becomes config region leader
2024-10-15 15:11:24,993 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.m.l.s.HeartbeatService:96 - Heartbeat service is started successfully.
2024-10-15 15:11:24,995 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.m.l.s.StatisticsService:68 - LoadStatistics service is started successfully.
2024-10-15 15:11:25,002 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.m.l.s.EventService:104 - Event service is started successfully.
2024-10-15 15:11:25,027 [pool-10-IoTDB-Cluster-Event-Service-1] INFO  o.a.i.c.m.l.s.EventService:155 - [NodeStatistics] NodeStatisticsMap:
2024-10-15 15:11:25,028 [pool-10-IoTDB-Cluster-Event-Service-1] INFO  o.a.i.c.m.l.s.EventService:158 - [NodeStatistics]  nodeId{0}: null -> NodeStatistics{status=Running, statusReason='null'}
2024-10-15 15:11:25,038 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.ProcedureExecutor:282 - 16 procedure workers are started.
2024-10-15 15:11:25,040 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.m.ProcedureManager:179 - ProcedureManager is started successfully.
2024-10-15 15:11:25,032 [main] ERROR o.a.i.c.s.ConfigNode:236 - Meet error while starting up.
org.apache.iotdb.commons.exception.StartupException: Failed to start [Config Node service], because [IoTDB: failed to start Config Node service, because Could not create ServerSocket on address iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local/172.16.246.137:10710.]
        at org.apache.iotdb.commons.service.ThriftService.startService(ThriftService.java:133)
        at org.apache.iotdb.commons.service.ThriftService.start(ThriftService.java:70)
        at org.apache.iotdb.commons.service.RegisterManager.register(RegisterManager.java:52)
        at org.apache.iotdb.confignode.service.ConfigNode.setUpRPCService(ConfigNode.java:393)
        at org.apache.iotdb.confignode.service.ConfigNode.active(ConfigNode.java:141)
        at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.activeConfigNodeInstance(ConfigNodeCommandLine.java:97)
        at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.run(ConfigNodeCommandLine.java:79)
        at org.apache.iotdb.commons.ServerCommandLine.doMain(ServerCommandLine.java:58)
        at org.apache.iotdb.confignode.service.ConfigNode.main(ConfigNode.java:116)
2024-10-15 15:11:25,044 [main] INFO  o.a.i.c.s.ConfigNode:414 - Deactivating IoTDB-ConfigNode...
2024-10-15 15:11:25,045 [main] INFO  o.a.i.c.s.ThriftService:156 - IoTDB: Config Node service isn't running now
2024-10-15 15:11:25,046 [main] INFO  o.a.i.c.s.m.MetricService:127 - MetricService try to stop.
2024-10-15 15:11:25,048 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.m.RetryFailedTasksThread:86 - RetryFailMissions service is started successfully.
2024-10-15 15:11:25,054 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.m.p.PartitionManager:1416 - RegionCleaner is started successfully.
2024-10-15 15:11:25,063 [main] INFO  o.a.i.c.s.m.JvmGcMonitorMetrics:111 - JVM GC scheduled monitor is stopped successfully.
2024-10-15 15:11:25,079 [main] INFO  o.a.i.c.s.m.MetricService:132 - MetricService stop successfully.
2024-10-15 15:11:25,079 [main] INFO  o.a.i.c.m.p.a.r.PipeConfigNodeRuntimeAgent:75 - PipeRuntimeConfigNodeAgent stopped
2024-10-15 15:11:25,080 [main] INFO  o.a.i.c.s.RegisterManager:73 - deregister all service.
2024-10-15 15:11:25,088 [main] INFO  o.a.r.s.i.RaftServerProxy:418 - 0: close
2024-10-15 15:11:25,090 [main] INFO  o.a.r.g.s.GrpcService:311 - 0: shutdown server GrpcServerProtocolService now
2024-10-15 15:11:25,091 [0-impl-thread1] INFO  o.a.r.s.i.RaftServerImpl:501 - 0@group-000000000000: shutdown
2024-10-15 15:11:25,093 [0-impl-thread1] INFO  o.a.r.util.JmxRegister:74 - Successfully un-registered JMX Bean with object name Ratis:service=RaftServer,group=group-000000000000,id=0
2024-10-15 15:11:25,094 [0-impl-thread1] INFO  o.a.r.s.impl.RoleInfo:103 - 0: shutdown 0@group-000000000000-LeaderStateImpl
2024-10-15 15:11:25,095 [0-impl-thread1] INFO  o.a.r.s.i.PendingRequests:287 - 0@group-000000000000-PendingRequests: sendNotLeaderResponses
2024-10-15 15:11:25,096 [pool-1-IoTDB-ConfigNode-Manager-Recovery-1] INFO  o.a.i.c.c.IoTDBThreadPoolFactory:233 - new scheduled thread pool: CQ-Scheduler
2024-10-15 15:11:25,102 [pool-1-IoTDB-ConfigNode-Manager-Recovery-2] INFO  o.a.i.c.m.p.c.r.PipeMetaSyncer:81 - PipeMetaSyncer is started successfully.
2024-10-15 15:11:25,120 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.c.s.ConfigRegionStateMachine:329 - Current node [nodeId: 0, ip:port: TEndPoint(ip:iotdb-confignode-0.iotdb-confignode.custom-iotdb-cluster.svc.cluster.local, port:10720)] as config region leader is ready to work
2024-10-15 15:11:25,121 [pool-1-IoTDB-ConfigNode-Manager-Recovery-4] INFO  o.a.i.c.m.ClusterManager:48 - clusterID: 19f0ef96-0850-4b8e-a8ae-a59e4a5aafff
2024-10-15 15:11:25,121 [pool-1-IoTDB-ConfigNode-Manager-Recovery-3] INFO  o.a.i.c.m.p.c.r.PipeHeartbeatScheduler:78 - PipeHeartbeat is started successfully.
2024-10-15 15:11:25,127 [pool-1-IoTDB-ConfigNode-Manager-Recovery-5] INFO  o.a.i.c.m.s.SubscriptionMetaSyncer:73 - SubscriptionMetaSyncer is started successfully.
2024-10-15 15:11:25,139 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:548 - [ConfigNodeSnapshot] Start to take snapshot for org.apache.iotdb.confignode.persistence.ClusterInfo into /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/sm/.tmp.7_18
2024-10-15 15:11:25,137 [0-impl-thread1] INFO  o.a.r.s.i.StateMachineUpdater:164 - 0@group-000000000000-StateMachineUpdater: set stopIndex = 18
2024-10-15 15:11:25,165 [main] WARN  o.a.r.s.i.RaftServerProxy:424 - 0: Failed to close GRPC server
java.io.InterruptedIOException: 0: shutdown server GrpcServerProtocolService failed
        at org.apache.ratis.util.IOUtils.toInterruptedIOException(IOUtils.java:49)
        at org.apache.ratis.grpc.server.GrpcService.closeImpl(GrpcService.java:318)
        at org.apache.ratis.util.LifeCycle.lambda$checkStateAndClose$7(LifeCycle.java:306)
        at org.apache.ratis.util.LifeCycle.checkStateAndClose(LifeCycle.java:326)
        at org.apache.ratis.util.LifeCycle.checkStateAndClose(LifeCycle.java:304)
        at org.apache.ratis.server.RaftServerRpcWithProxy.close(RaftServerRpcWithProxy.java:80)
        at org.apache.ratis.server.impl.RaftServerProxy.lambda$close$9(RaftServerProxy.java:422)
        at org.apache.ratis.util.LifeCycle.lambda$checkStateAndClose$7(LifeCycle.java:306)
        at org.apache.ratis.util.LifeCycle.checkStateAndClose(LifeCycle.java:326)
        at org.apache.ratis.util.LifeCycle.checkStateAndClose(LifeCycle.java:304)
        at org.apache.ratis.server.impl.RaftServerProxy.close(RaftServerProxy.java:417)
        at org.apache.iotdb.consensus.ratis.RatisConsensus.stop(RatisConsensus.java:231)
        at org.apache.iotdb.confignode.manager.consensus.ConsensusManager.close(ConsensusManager.java:109)
        at org.apache.iotdb.confignode.manager.ConfigManager.close(ConfigManager.java:347)
        at org.apache.iotdb.confignode.service.ConfigNode.deactivate(ConfigNode.java:418)
        at org.apache.iotdb.confignode.service.ConfigNode.stop(ConfigNode.java:425)
        at org.apache.iotdb.confignode.service.ConfigNode.active(ConfigNode.java:237)
        at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.activeConfigNodeInstance(ConfigNodeCommandLine.java:97)
        at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.run(ConfigNodeCommandLine.java:79)
        at org.apache.iotdb.commons.ServerCommandLine.doMain(ServerCommandLine.java:58)
        at org.apache.iotdb.confignode.service.ConfigNode.main(ConfigNode.java:116)
Caused by: java.lang.InterruptedException: null
        at java.base/java.lang.Object.wait(Native Method)
        at java.base/java.lang.Object.wait(Unknown Source)
        at org.apache.ratis.thirdparty.io.grpc.internal.ServerImpl.awaitTermination(ServerImpl.java:322)
        at org.apache.ratis.grpc.server.GrpcService.closeImpl(GrpcService.java:315)
        ... 19 common frames omitted
2024-10-15 15:11:25,180 [main] INFO  o.a.i.c.p.ProcedureExecutor:870 - Stopping
2024-10-15 15:11:25,179 [JvmPauseMonitor0] INFO  o.a.r.u.JvmPauseMonitor:152 - JvmPauseMonitor-0: Stopped
2024-10-15 15:11:25,188 [ProcExecWorker-2] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-2 terminated.
2024-10-15 15:11:25,194 [ProcExecWorker-4] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-4 terminated.
2024-10-15 15:11:25,195 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:553 - [ConfigNodeSnapshot] Finish to take snapshot for org.apache.iotdb.confignode.persistence.ClusterInfo, time consumption: 56 ms
2024-10-15 15:11:25,193 [ProcExecWorker-1] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-1 terminated.
2024-10-15 15:11:25,195 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:548 - [ConfigNodeSnapshot] Start to take snapshot for org.apache.iotdb.confignode.persistence.node.NodeInfo into /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/sm/.tmp.7_18
2024-10-15 15:11:25,196 [ProcExecWorker-5] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-5 terminated.
2024-10-15 15:11:25,192 [main] WARN  o.a.i.c.p.StoppableThread:46 - ProcedureTimeoutExecutor join wait got interrupted
java.lang.InterruptedException: null
        at java.base/java.lang.Object.wait(Native Method)
        at java.base/java.lang.Thread.join(Unknown Source)
        at org.apache.iotdb.confignode.procedure.StoppableThread.awaitTermination(StoppableThread.java:40)
        at org.apache.iotdb.confignode.procedure.ProcedureExecutor.join(ProcedureExecutor.java:876)
        at org.apache.iotdb.confignode.manager.ProcedureManager.stopExecutor(ProcedureManager.java:187)
        at org.apache.iotdb.confignode.manager.ConfigManager.close(ConfigManager.java:353)
        at org.apache.iotdb.confignode.service.ConfigNode.deactivate(ConfigNode.java:418)
        at org.apache.iotdb.confignode.service.ConfigNode.stop(ConfigNode.java:425)
        at org.apache.iotdb.confignode.service.ConfigNode.active(ConfigNode.java:237)
        at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.activeConfigNodeInstance(ConfigNodeCommandLine.java:97)
        at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.run(ConfigNodeCommandLine.java:79)
        at org.apache.iotdb.commons.ServerCommandLine.doMain(ServerCommandLine.java:58)
        at org.apache.iotdb.confignode.service.ConfigNode.main(ConfigNode.java:116)
2024-10-15 15:11:25,199 [ProcExecWorker-6] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-6 terminated.
2024-10-15 15:11:25,199 [ProcExecWorker-3] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-3 terminated.
2024-10-15 15:11:25,199 [ProcExecWorker-7] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-7 terminated.
2024-10-15 15:11:25,202 [ProcExecWorker-10] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-10 terminated.
2024-10-15 15:11:25,209 [ProcExecWorker-11] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-11 terminated.
2024-10-15 15:11:25,209 [ProcExecWorker-12] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-12 terminated.
2024-10-15 15:11:25,201 [ProcExecWorker-9] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-9 terminated.
2024-10-15 15:11:25,214 [ProcExecWorker-13] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-13 terminated.
2024-10-15 15:11:25,216 [ProcExecWorker-14] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-14 terminated.
2024-10-15 15:11:25,217 [ProcExecWorker-15] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-15 terminated.
2024-10-15 15:11:25,217 [ProcExecWorker-8] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-8 terminated.
2024-10-15 15:11:25,215 [main] WARN  o.a.i.c.p.StoppableThread:46 - ProcedureWorkerThreadMonitor join wait got interrupted
java.lang.InterruptedException: null
        at java.base/java.lang.Object.wait(Native Method)
        at java.base/java.lang.Thread.join(Unknown Source)
        at org.apache.iotdb.confignode.procedure.StoppableThread.awaitTermination(StoppableThread.java:40)
        at org.apache.iotdb.confignode.procedure.ProcedureExecutor.join(ProcedureExecutor.java:877)
        at org.apache.iotdb.confignode.manager.ProcedureManager.stopExecutor(ProcedureManager.java:187)
        at org.apache.iotdb.confignode.manager.ConfigManager.close(ConfigManager.java:353)
        at org.apache.iotdb.confignode.service.ConfigNode.deactivate(ConfigNode.java:418)
        at org.apache.iotdb.confignode.service.ConfigNode.stop(ConfigNode.java:425)
        at org.apache.iotdb.confignode.service.ConfigNode.active(ConfigNode.java:237)
        at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.activeConfigNodeInstance(ConfigNodeCommandLine.java:97)
        at org.apache.iotdb.confignode.service.ConfigNodeCommandLine.run(ConfigNodeCommandLine.java:79)
        at org.apache.iotdb.commons.ServerCommandLine.doMain(ServerCommandLine.java:58)
        at org.apache.iotdb.confignode.service.ConfigNode.main(ConfigNode.java:116)
2024-10-15 15:11:25,219 [ProcExecWorker-16] INFO  o.a.i.c.p.ProcedureExecutor$WorkerThread:760 - Procedure worker ProcExecWorker-16 terminated.
2024-10-15 15:11:25,229 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:553 - [ConfigNodeSnapshot] Finish to take snapshot for org.apache.iotdb.confignode.persistence.node.NodeInfo, time consumption: 34 ms
2024-10-15 15:11:25,230 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:548 - [ConfigNodeSnapshot] Start to take snapshot for org.apache.iotdb.confignode.persistence.schema.ClusterSchemaInfo into /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/sm/.tmp.7_18
2024-10-15 15:11:25,236 [main] WARN  o.a.i.c.p.ProcedureExecutor:884 - ProcedureExecutor threadGroup java.lang.ThreadGroup[name=ProcedureWorkerGroup,maxpri=10] contains running threads which are used by non-procedure module.
java.lang.ThreadGroup[name=ProcedureWorkerGroup,maxpri=10]
    Thread[ProcedureTimeoutExecutor,5,ProcedureWorkerGroup]
    Thread[ProcedureWorkerThreadMonitor,5,ProcedureWorkerGroup]
2024-10-15 15:11:25,240 [main] INFO  o.a.i.c.m.ProcedureManager:189 - ProcedureManager is stopped successfully.
2024-10-15 15:11:25,241 [main] INFO  o.a.i.c.s.ConfigNode:420 - IoTDB-ConfigNode is deactivated.
2024-10-15 15:11:25,256 [Thread-0] INFO  o.a.i.c.s.ConfigNodeShutdownHook:49 - ConfigNode exiting...
2024-10-15 15:11:25,256 [Thread-0] INFO  o.a.i.c.s.ConfigNode:414 - Deactivating IoTDB-ConfigNode...
2024-10-15 15:11:25,257 [Thread-0] INFO  o.a.i.c.s.RegisterManager:73 - deregister all service.
2024-10-15 15:11:25,264 [Thread-0] INFO  o.a.i.c.s.ConfigNode:420 - IoTDB-ConfigNode is deactivated.
2024-10-15 15:11:25,273 [Thread-0] INFO  o.a.i.c.s.ConfigNodeShutdownHook:92 - IoTDB-ConfigNode exits. Jvm memory usage: 0 GB 27 MB 807 KB 776 B
2024-10-15 15:11:25,274 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:553 - [ConfigNodeSnapshot] Finish to take snapshot for org.apache.iotdb.confignode.persistence.schema.ClusterSchemaInfo, time consumption: 44 ms
2024-10-15 15:11:25,278 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:548 - [ConfigNodeSnapshot] Start to take snapshot for org.apache.iotdb.confignode.persistence.partition.PartitionInfo into /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/sm/.tmp.7_18
2024-10-15 15:11:25,372 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:553 - [ConfigNodeSnapshot] Finish to take snapshot for org.apache.iotdb.confignode.persistence.partition.PartitionInfo, time consumption: 94 ms
2024-10-15 15:11:25,373 [0@group-000000000000-StateMachineUpdater] INFO  o.a.i.c.p.e.ConfigPlanExecutor:548 - [ConfigNodeSnapshot] Start to take snapshot for org.apache.iotdb.confignode.persistence.AuthorInfo into /iotdb/sbin/../data/confignode/consensus/47474747-4747-4747-4747-000000000000/sm/.tmp.7_18
2024-10-15 15:11:25,369 [pool-1-IoTDB-ConfigNode-Manager-Recovery-1] WARN  o.a.i.c.m.cq.CQManager:143 - Unexpected error happened while fetching cq list:
org.apache.iotdb.consensus.exception.RatisRequestFailedException: Ratis request failed Unexpected exception class: RaftClientReply:client-B92144085F2C->0@group-000000000000, cid=1, FAILED org.apache.ratis.protocol.exceptions.ServerNotReadyException: 0@group-000000000000 is not in [RUNNING]: current state is CLOSING, logIndex=0, commits[0:c18]
        at org.apache.iotdb.consensus.ratis.RatisConsensus.read(RatisConsensus.java:378)
        at org.apache.iotdb.confignode.manager.consensus.ConsensusManager.read(ConsensusManager.java:335)
        at org.apache.iotdb.confignode.manager.cq.CQManager.startCQScheduler(CQManager.java:139)
        at org.apache.iotdb.confignode.consensus.statemachine.ConfigRegionStateMachine.lambda$notifyLeaderReady$3(ConfigRegionStateMachine.java:305)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
        at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.lang.IllegalStateException: Unexpected exception class: RaftClientReply:client-B92144085F2C->0@group-000000000000, cid=1, FAILED org.apache.ratis.protocol.exceptions.ServerNotReadyException: 0@group-000000000000 is not in [RUNNING]: current state is CLOSING, logIndex=0, commits[0:c18]
        at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:77)
        at org.apache.ratis.protocol.RaftClientReply.<init>(RaftClientReply.java:170)
        at org.apache.ratis.protocol.RaftClientReply$Builder.build(RaftClientReply.java:61)
        at org.apache.ratis.server.impl.RaftServerImpl.newExceptionReply(RaftServerImpl.java:713)
        at org.apache.ratis.server.impl.RaftServerImpl.submitClientRequestAsync(RaftServerImpl.java:905)
        at org.apache.ratis.protocol.RaftClientAsynchronousProtocol.submitClientRequestAsync(RaftClientAsynchronousProtocol.java:34)
        at org.apache.ratis.server.impl.RaftServerImpl.submitClientRequest(RaftServerImpl.java:1139)
        at org.apache.ratis.server.impl.RaftServerProxy.submitClientRequest(RaftServerProxy.java:463)
        at org.apache.iotdb.consensus.ratis.RatisConsensus.lambda$doRead$9(RatisConsensus.java:402)
        at org.apache.iotdb.consensus.ratis.utils.Retriable.attempt(Retriable.java:60)
        at org.apache.iotdb.consensus.ratis.utils.Retriable.attempt(Retriable.java:113)
        at org.apache.iotdb.consensus.ratis.RatisConsensus.doRead(RatisConsensus.java:399)
        at org.apache.iotdb.consensus.ratis.RatisConsensus.read(RatisConsensus.java:364)
        ... 8 common frames omitted

myysophia commented 1 month ago

@SeanGaluzzi you can try this yaml without configmap。

configNode

apiVersion: apps/v1
kind: StatefulSet
metadata:
name: iotdb-confignode
namespace: iotdb
spec:
replicas: 1
revisionHistoryLimit: 10
selector:
matchLabels:
  app.kubernetes.io/instance: iotdb-cn1.3
  app.kubernetes.io/name: iotdb-confignode
serviceName: iotdb-confignode
template:
metadata:
  creationTimestamp: null
  labels:
    app.kubernetes.io/instance: iotdb-cn1.3
    app.kubernetes.io/name: iotdb-confignode
spec:
  affinity:
    podAntiAffinity:
      requiredDuringSchedulingIgnoredDuringExecution:
      - labelSelector:
          matchExpressions:
          - key: app.kubernetes.io/name
            operator: In
            values:
            - iotdb-confignode
        topologyKey: kubernetes.io/hostname
  containers:
  - env:
    - name: MY_NS_NAME
      valueFrom:
        fieldRef:
          apiVersion: v1
          fieldPath: metadata.namespace
    - name: MY_POD_NAME
      valueFrom:
        fieldRef:
          apiVersion: v1
          fieldPath: metadata.name
    - name: cn_internal_address
      value: $(MY_POD_NAME).iotdb-confignode.$(MY_NS_NAME).svc.cluster.local
    - name: cn_seed_config_node
      value: iotdb-confignode-0.iotdb-confignode.$(MY_NS_NAME).svc.cluster.local:10710
    - name: schema_replication_factor
      value: "1"
    - name: data_replication_factor
      value: "1"
    - name: cn_internal_port
      value: "10710"
    - name: cn_consensus_port
      value: "10720"
    - name: schema_region_consensus_protocol_class
      value: org.apache.iotdb.consensus.ratis.RatisConsensus
    - name: config_node_consensus_protocol_class
      value: org.apache.iotdb.consensus.ratis.RatisConsensus
    - name: data_region_consensus_protocol_class
      value: org.apache.iotdb.consensus.iot.IoTConsensus
    - name: cn_metric_reporter_list
      value: PROMETHEUS
    - name: cn_metric_level
      value: CORE
    - name: cn_metric_prometheus_reporter_port
      value: "9092"
    image: apache/iotdb:1.3.2-confignode
    imagePullPolicy: IfNotPresent
    name: iotdb-confignode
    ports:
    - containerPort: 10710
      name: tcp-10710
      protocol: TCP
    - containerPort: 10720
      name: tcp-10720
      protocol: TCP
    - containerPort: 10730
      name: tcp-10730
      protocol: TCP
    - containerPort: 10740
      name: tcp-10740
      protocol: TCP
    - containerPort: 9092
      name: tcp-9092
      protocol: TCP
    resources:
      limits:
        cpu: "1"
        memory: 2Gi
      requests:
        cpu: "1"
        memory: 1Gi
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
    volumeMounts:
    - mountPath: /etc/localtime
      name: host-time
    - mountPath: /iotdb/data/
      name: iotdb-confignode-data
  dnsPolicy: ClusterFirst
  restartPolicy: Always
  schedulerName: default-scheduler
  securityContext: {}
  terminationGracePeriodSeconds: 30
  volumes:
  - hostPath:
      path: /etc/localtime
      type: ""
    name: host-time
updateStrategy:
rollingUpdate:
  partition: 0
type: RollingUpdate
volumeClaimTemplates:
- apiVersion: v1
kind: PersistentVolumeClaim
metadata:
  creationTimestamp: null
  name: iotdb-confignode-data
spec:
  accessModes:
  - ReadWriteOnce
  resources:
    requests:
      storage: 20Gi
  storageClassName: gp2
  volumeMode: Filesystem

datanode


apiVersion: apps/v1
kind: StatefulSet
metadata:
name: iotdb-datanode
namespace: iotdb
spec:
replicas: 1
revisionHistoryLimit: 10
selector:
matchLabels:
  app.kubernetes.io/instance: iotdb-dn1.3
  app.kubernetes.io/name: iotdb-datanode
serviceName: iotdb-datanode
template:
metadata:
  annotations:
    kubectl.kubernetes.io/restartedAt: "2024-08-14T11:07:05+08:00"
  creationTimestamp: null
  labels:
    app.kubernetes.io/instance: iotdb-dn1.3
    app.kubernetes.io/name: iotdb-datanode
spec:
  affinity:
    podAntiAffinity: {}
  containers:
  - env:
    - name: MY_POD_NAME
      valueFrom:
        fieldRef:
          apiVersion: v1
          fieldPath: metadata.name
    - name: MY_NS_NAME
      valueFrom:
        fieldRef:
          apiVersion: v1
          fieldPath: metadata.namespace
    - name: dn_rpc_address
      value: $(MY_POD_NAME).iotdb-datanode.$(MY_NS_NAME).svc.cluster.local
    - name: dn_internal_address
      value: $(MY_POD_NAME).iotdb-datanode.$(MY_NS_NAME).svc.cluster.local
    - name: dn_seed_config_node
      value: iotdb-confignode-0.iotdb-confignode.$(MY_NS_NAME).svc.cluster.local:10710
    - name: schema_replication_factor
      value: "1"
    - name: data_replication_factor
      value: "1"
    - name: dn_rpc_port
      value: "6667"
    - name: dn_mpp_data_exchange_port
      value: "10740"
    - name: dn_schema_region_consensus_port
      value: "10750"
    - name: dn_data_region_consensus_port
      value: "10760"
    - name: schema_region_consensus_protocol_class
      value: org.apache.iotdb.consensus.ratis.RatisConsensus
    - name: config_node_consensus_protocol_class
      value: org.apache.iotdb.consensus.ratis.RatisConsensus
    - name: data_region_consensus_protocol_class
      value: org.apache.iotdb.consensus.iot.IoTConsensus
    - name: enable_auto_create_schema
      value: "true"
    - name: dn_metric_reporter_list
      value: PROMETHEUS
    - name: dn_metric_level
      value: CORE
    - name: dn_metric_prometheus_reporter_port
      value: "9091"
    image: apache/iotdb:1.3.2-datanode
    imagePullPolicy: IfNotPresent
    name: iotdb-datanode
    ports:
    - containerPort: 10710
      name: tcp-10710
      protocol: TCP
    - containerPort: 10720
      name: tcp-10720
      protocol: TCP
    - containerPort: 10730
      name: tcp-10730
      protocol: TCP
    - containerPort: 10740
      name: tcp-10740
      protocol: TCP
    - containerPort: 6667
      name: tcp-6667
      protocol: TCP
    - containerPort: 9091
      name: tcp-9091
      protocol: TCP
    resources:
      limits:
        cpu: "1"
        memory: 4Gi
      requests:
        cpu: "1"
        memory: 1Gi
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
    volumeMounts:
    - mountPath: /etc/localtime
      name: host-time
    - mountPath: /iotdb/data/
      name: iotdb-datanode-data
    - mountPath: /iotdb/conf/datanode-env.sh
      name: iotdb-datanode-env
      subPath: datanode-env.sh
  dnsPolicy: ClusterFirst
  restartPolicy: Always
  schedulerName: default-scheduler
  securityContext: {}
  terminationGracePeriodSeconds: 30
  volumes:
  - hostPath:
      path: /etc/localtime
      type: ""
    name: host-time
  - configMap:
      defaultMode: 420
      items:
      - key: datanode-env.sh
        path: datanode-env.sh
      name: iotdb-datanode-env
    name: iotdb-datanode-env
  - configMap:
      defaultMode: 420
      items:
      - key: iotdb-common.properties
        path: ' /iotdb/conf/iotdb-common.properties'
      name: iotdb-common-env
    name: iotdb-common-env
updateStrategy:
rollingUpdate:
  partition: 0
type: RollingUpdate
volumeClaimTemplates:
- apiVersion: v1
kind: PersistentVolumeClaim
metadata:
  creationTimestamp: null
  name: iotdb-datanode-data
spec:
  accessModes:
  - ReadWriteOnce
  resources:
    requests:
      storage: 20Gi
  storageClassName: gp2
  volumeMode: Filesystem

apache / iotdb