After restarting one node there is extreme decrease in Ops/sec and even timeout

Operations Configuration
1

Hi I am using aerospike-6.1.0.1. I am running into a issue where the write throughput is reduced from 1000 ops/second to 0.8 ops/second (even timeout). When I set the new cluster with 2 nodes and Replication factor 2, it works perfectly fine with 1000 ops/second, but if I restart one node and wait for the migration to get complete the write ops reduces to mere 0.8 ops/second. But read ops are fine, and if I reduce the replication factor from 2 to 1 it works fine.

The issue happens only after I restart one node. Then after remove the whole aerospike setup and installing again, it works fine until restart of a node.

The two nodes are aws i3.2xlarge

log that gets prints (I dont see any error or warning logs):

Apr 26 2023 21:52:05 GMT: INFO (drv_ssd): (drv_ssd.c:1893) {ycsb} /dev/nvme0n1: used-bytes 98496 free-wblocks 14495783 write-q 0 write (0,0.0) defrag-q 0 defrag-read (0,0.0) defrag-write (0,0.0)
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:163) NODE-ID bb9ae55b9355c06 CLUSTER-SIZE 2
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:234)    cluster-clock: skew-ms 0
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:255)    system: total-cpu-pct 0 user-cpu-pct 0 kernel-cpu-pct 0 free-mem-kbytes 62056704 free-mem-pct 98 thp-mem-kbytes 0
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:277)    process: cpu-pct 1 threads (9,61,104,104) heap-kbytes (1545219,1547368,1784320) heap-efficiency-pct 99.9
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:287)    in-progress: info-q 0 rw-hash 0 proxy-hash 0 tree-gc-q 0 long-queries 0
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:311)    fds: proto (2,133,131) heartbeat (1,7,6) fabric (26,38,12)
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:320)    heartbeat-received: self 4 foreign 6980
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:346)    fabric-bytes-per-second: bulk (0,0) ctrl (0,0) meta (0,0) rw (0,0)
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:405) {ycsb} objects: all 19 master 9 prole 10 non-replica 0
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:469) {ycsb} migrations: complete
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:495) {ycsb} memory-usage: total-bytes 1216 index-bytes 1216 set-index-bytes 0 sindex-bytes 0 used-pct 0.00
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:564) {ycsb} device-usage: used-bytes 98496 avail-pct 99 cache-read-pct 0.00
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:613) {ycsb} client: tsvc (0,0) proxy (0,0,0) read (0,0,0,0,0) write (8,0,1,0) delete (0,0,0,0,0) udf (0,0,0,0) lang (0,0,0,0)
Apr 26 2023 21:52:05 GMT: INFO (info): (ticker.c:980) {ycsb} retransmits: migration 87 all-read 0 all-write (0,15) all-delete (0,0) all-udf (0,0) all-batch-sub 0 udf-sub (0,0) ops-sub (0,0)
Apr 26 2023 21:52:05 GMT: INFO (info): (hist.c:320) histogram dump: {ycsb}-write (8 total) msec
Apr 26 2023 21:52:05 GMT: INFO (info): (hist.c:331)  (00: 0000000001) (10: 0000000004) (11: 0000000002) (12: 0000000001)

Configuration of aerospike.config:

 # Aerospike database configuration file.

service {
    cluster-name AerospikeCluster1
    service-threads 40
    proto-fd-max 15000
}

logging {
    # Log file must be an absolute path.
    file /home/ubuntu/aerospike.log {
        context any info
    }
}

network {
    service {
        address any
		port 3000
		access-address 172.31.19.106
    }

       heartbeat {
                mode mesh
                port 3002

		mesh-seed-address-port 172.31.24.176 3002
		mesh-seed-address-port 172.31.19.106 3002
                # To use unicast-mesh heartbeats, remove the 3 lines above, and see
                # aerospike_mesh.conf for alternative.

                interval 150
                timeout 50
        }
    fabric {
	 send-threads 8
	 port 3001
    }

    info {
         port 3003
    }
}

namespace ycsb {
        replication-factor 2
        memory-size 40G


        storage-engine device {
            device /dev/nvme0n1
            write-block-size 128K
        }

}

@Brian @kporter could you help me :pray:

2

Based on what I see here, my hunch is that you are seeing this behavior during the 7.5 seconds (heartbeat interval * timeout) after the noce is restarted. The standard configuration used 1.5 seconds (150 interval and 10 timeout). Try reducing the timeout back to 10. This will still leave a 1.5 second window where write transactions may timeout - if you need to eliminate that during maintenance events, you would need to quiesce (EE only) the node and recluster before shutting it down.

If that isn’t the problem, could you share more information about the write load (e.g. command or code used)?

1 Like
3

@kporter Thanks a lot for replying. Issue happens even after 7.5 seconds of restart and remains the same afterwards. I waited for 20 mins for migration to complete. I am using YCSB to load test the two node cluster, it is a java code that sends the inserts to the aerospike server. Command and output for YCSB attached below:

Before restarting 1 node (1292 ops/second all Insert):

image
image1920Ă—406 110 KB

After restarting 1 node and waiting for 20 mins for the migration to complete (0.8 ops/second):

image
image1920Ă—540 148 KB

I am using two EC2 server in the same subnet and have provided the private ip address in the network → service.access-address.

4

Can you share workloads/customWorkload?

Also, to reduce the number of variables could you try with this config (will need to be adjusted for the other node):

# Aerospike database configuration file.

service {
    cluster-name AerospikeCluster1
    service-threads 40
    proto-fd-max 100000
}

logging {
    # Log file must be an absolute path.
    file /home/ubuntu/aerospike.log {
        context any info
    }
}

network {
    service {
        address 172.31.19.106
        port 3000
        access-address 172.31.19.106
    }

    heartbeat {
        address 172.31.19.106
        mode mesh
        port 3002

        mesh-seed-address-port 172.31.24.176 3002
	mesh-seed-address-port 172.31.19.106 3002

        interval 150
        timeout 10
    }

    fabric {
        address 172.31.19.106
        port 3001
    }

    info {
         port 3003
    }
}

namespace ycsb {
    replication-factor 2
    memory-size 40G

    storage-engine device {
        device /dev/nvme0n1
        write-block-size 128K
    }
}
1 Like
5

@kporter Thanks for replying. I spent a lot of time figuring this out, and exactly the same that you have mentioned in the config sent by you, my config was missing address in heartbeat and fabric. After adding this parameter in the config and restarting both the servers everything works fine now.

Could you throw some light on what was the issue here? It started the first time, but once I did the restart the throughput reduced to 1ops/sec

Also I can see you have increased the proto-fd-max, currently active connections are not that high, but will surely check and update the same.

6

I added the address field to remove the possibility of picking up multiple NICs for the various network contexts. I’ve seen issues where multiple nodes have an interface with the same IP which had similar effects.

I’m not sure what the case was here - you could revert the config back, but also remove the access-address1 config and run:

asadm -e "enable;asinfo -v service"

Your logs contained a bit of a hint that something was going on with the network interfaces:

heartbeat-received: self 4 foreign 6980

Mesh heartbeats shouldn’t ever receive from self.

7

@kporter Yes just checked the logs, the self heartbeat is not 0 (screenshot attached). I have attached the logs and other outputs as well. The issue is now resolved and I am getting the same ops/sec before and after restart, without any detrimental effect. Also the migration happens within few seconds and very quick, earlier it was taking like forever.

I have attached the final config to this mail, that seems to be fine now. Also I went through the document and also defined the parameter node-id-interface to ens3 (check ifconfig) in the service layer, in order to avoid node-id change, which would rather have happened whenever a random interface was chosen. Also I have explicitly defined the exact network interface in all the address section rather than the ip, in order to avoid any other new interface with the same ip.

Logs:

image
image3456Ă—600 456 KB

Output of asadm -e “enable;asinfo -v service”:

image
image1620Ă—272 36 KB

ifconfig output:

image
image1428Ă—1096 188 KB

Current aerospike.conf file

service {
        user root
        group root
        pidfile /var/run/aerospike/asd.pid
        service-threads 40
        proto-fd-max 15000
        node-id-interface ens3
}

logging {
    # Log file must be an absolute path.
    file /home/ubuntu/aerospike.log {
        context any info
    }
}

network {
    service {
        address ens3
        port 3000
        access-address ens3
    }

       heartbeat {
                address ens3
                mode mesh
                port 3002
	            mesh-seed-address-port 172.31.19.106 3002
                interval 150
                timeout 10
        }
    fabric {
        address ens3
        port 3001
    }

    info {
         port 3003
    }
}

namespace ycsb {
        replication-factor 2
        memory-size 40G

        storage-engine device {
            device /dev/nvme0n1
            write-block-size 128K
        }

}
8

This topic was automatically closed 84 days after the last reply. New replies are no longer allowed.