Unable to start aerospike service, it is stuck while starting

1

My aerospike instance is stuck here.

sudo /etc/init.d/aerospike start
Starting and checking aerospike:

My conf file /etc/aerospike/aerospike.conf.

# Aerospike database configuration file for deployments using mesh heartbeats.

service {
	user root
	group root
	paxos-single-replica-limit 1 # Number of nodes where the replica count is automatically reduced to 1.
	pidfile /var/run/aerospike/asd.pid
	proto-fd-max 150000
}

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

network {
	service {
		address any
		port 3000
	}

	heartbeat {
		mode mesh
		port 3002 # Heartbeat port for this node.

		# List one or more other nodes, one ip-address & port per line:
		mesh-seed-address-port 10.10.1.193 3002
#		mesh-seed-address-port 10.10.10.11 3002
#		mesh-seed-address-port 10.10.10.12 3002
#		mesh-seed-address-port 10.10.10.13 3002
#		mesh-seed-address-port 10.10.10.14 3002

		interval 250
		timeout 10
	}

	fabric {
		port 3001
	}

	info {
		port 3003
	}
}

namespace test {
	replication-factor 2
	memory-size 4G
	default-ttl 0 # 30 days, use 0 to never expire/evict.

	# storage-eingine memory
        storage-engine device {
                file /opt/aerospike/data/test.dat
                filesize 16G
                data-in-memory true # Store data in memory in addition to file.
       }
}

namespace bar {
	replication-factor 2
	memory-size 4G
	default-ttl 0 # 30 days, use 0 to never expire/evict.

	# storage-engine memory

	# To use file storage backing, comment out the line above and use the
	# following lines instead.
	storage-engine device {
		file /opt/aerospike/data/bar.dat
		filesize 16G
		data-in-memory true # Store data in memory in addition to file.
	}
}

I see this when I reboot and do sudo service aerospike start

Increasing read socket buffer limit (/proc/sys/net/core/rmem_max): 212992 -> 15728640

Increasing write socket buffer limit (/proc/sys/net/core/wmem_max): 212992 -> 5242880
2

Could you you share the log output?

3

My log output from /var/log/aerospike/aerospike.log.

Aug 27 2020 12:49:38 GMT: INFO (info): (hist.c:257)  (04: 0000000040) (05: 0000000032) (06: 0000000030) (07: 0000000008)
Aug 27 2020 12:49:38 GMT: INFO (info): (hist.c:240) histogram dump: {test}-query (50746 total) msec
Aug 27 2020 12:49:38 GMT: INFO (info): (hist.c:257)  (00: 0000044668) (01: 0000000270) (02: 0000000661) (03: 0000001533)
Aug 27 2020 12:49:38 GMT: INFO (info): (hist.c:257)  (04: 0000002224) (05: 0000000951) (06: 0000000414) (07: 0000000025)
Aug 27 2020 12:49:38 GMT: INFO (info): (hist.c:240) histogram dump: {test}-query-rec-count (24048 total) count
Aug 27 2020 12:49:38 GMT: INFO (info): (hist.c:257)  (01: 0000002418) (02: 0000011993) (03: 0000005168) (04: 0000004098)
Aug 27 2020 12:49:38 GMT: INFO (info): (hist.c:266)  (05: 0000000371)
Aug 27 2020 12:49:38 GMT: INFO (info): (ticker.c:408) {bar} objects: all 1 master 1 prole 0 non-replica 0
Aug 27 2020 12:49:38 GMT: INFO (info): (ticker.c:469) {bar} migrations: complete
Aug 27 2020 12:49:38 GMT: INFO (info): (ticker.c:488) {bar} memory-usage: total-bytes 87 index-bytes 64 sindex-bytes 0 data-bytes 23 used-pct 0.00
Aug 27 2020 12:49:38 GMT: INFO (info): (ticker.c:518) {bar} device-usage: used-bytes 64 avail-pct 99
Aug 27 2020 12:49:38 GMT: WARNING (socket): (socket.c:746) (repeated:39) Timeout while connecting
Aug 27 2020 12:49:38 GMT: WARNING (hb): (hb.c:4845) (repeated:39) could not create heartbeat connection to node {10.10.1.193:3002}
Aug 27 2020 12:49:38 GMT: WARNING (socket): (socket.c:814) (repeated:39) Error while connecting socket to 10.10.1.193:3002
Aug 27 2020 12:49:45 GMT: INFO (drv_ssd): (drv_ssd.c:2134) {bar} /opt/aerospike/data/bar.dat: used-bytes 64 free-wblocks 16374 write-q 0 write (0,0.0) defrag-q 0 defrag-read (1,0.0) defrag-write (0,0.0)
Aug 27 2020 12:49:45 GMT: INFO (nsup): (thr_sindex.c:493) {test} sindex-gc start
Aug 27 2020 12:49:46 GMT: INFO (nsup): (thr_sindex.c:524) {test} sindex-gc: Processed: 2039, found:0, deleted: 0: Total time: 962 ms
Aug 27 2020 12:49:47 GMT: INFO (drv_ssd): (drv_ssd.c:2134) {test} /opt/aerospike/data/test.dat: used-bytes 495104 free-wblocks 16355 write-q 0 write (13,0.0) defrag-q 0 defrag-read (19,0.0) defrag-write (0,0.0)
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:171) NODE-ID bb9381648f12802 CLUSTER-SIZE 1
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:247)    cluster-clock: skew-ms 0
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:277)    system-memory: free-kbytes 7919888 free-pct 96 heap-kbytes (2184030,2186496,2301952) heap-efficiency-pct 94.9
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:291)    in-progress: tsvc-q 0 info-q 0 nsup-delete-q 0 rw-hash 0 proxy-hash 0 tree-gc-q 0
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:313)    fds: proto (5,2971421,2971416) heartbeat (0,13,13) fabric (2,60,58)
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:322)    heartbeat-received: self 0 foreign 0
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:353)    fabric-bytes-per-second: bulk (0,0) ctrl (0,0) meta (0,0) rw (0,0)
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:408) {test} objects: all 1370 master 1370 prole 0 non-replica 0
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:469) {test} migrations: complete
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:488) {test} memory-usage: total-bytes 852403 index-bytes 87680 sindex-bytes 304732 data-bytes 459991 used-pct 0.02
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:518) {test} device-usage: used-bytes 495104 avail-pct 99
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:587) {test} client: tsvc (0,0) proxy (0,0,0) read (89908,0,0,15569) write (38392,0,0) delete (951,0,0,3) udf (0,0,0) lang (0,0,0,0)
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:667) {test} scan: basic (42738,0,0) aggr (0,0,0) udf-bg (2,0,0)
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:692) {test} query: basic (50746,0) aggr (0,0) udf-bg (0,0)
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:720) {test} udf-sub: tsvc (0,0) udf (3,0,0) lang (3,0,0,0)
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:240) histogram dump: {test}-read (105477 total) msec
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:257)  (00: 0000105365) (01: 0000000002) (02: 0000000001) (03: 0000000002)
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:257)  (04: 0000000022) (05: 0000000036) (06: 0000000040) (07: 0000000009)
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:240) histogram dump: {test}-write (38392 total) msec
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:257)  (00: 0000038278) (01: 0000000002) (02: 0000000001) (03: 0000000001)
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:257)  (04: 0000000040) (05: 0000000032) (06: 0000000030) (07: 0000000008)
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:240) histogram dump: {test}-query (50746 total) msec
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:257)  (00: 0000044668) (01: 0000000270) (02: 0000000661) (03: 0000001533)
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:257)  (04: 0000002224) (05: 0000000951) (06: 0000000414) (07: 0000000025)
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:240) histogram dump: {test}-query-rec-count (24048 total) count
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:257)  (01: 0000002418) (02: 0000011993) (03: 0000005168) (04: 0000004098)
Aug 27 2020 12:49:48 GMT: INFO (info): (hist.c:266)  (05: 0000000371)
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:408) {bar} objects: all 1 master 1 prole 0 non-replica 0
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:469) {bar} migrations: complete
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:488) {bar} memory-usage: total-bytes 87 index-bytes 64 sindex-bytes 0 data-bytes 23 used-pct 0.00
Aug 27 2020 12:49:48 GMT: INFO (info): (ticker.c:518) {bar} device-usage: used-bytes 64 avail-pct 99
Aug 27 2020 12:49:48 GMT: WARNING (socket): (socket.c:746) (repeated:40) Timeout while connecting
Aug 27 2020 12:49:48 GMT: WARNING (hb): (hb.c:4845) (repeated:40) could not create heartbeat connection to node {10.10.1.193:3002}
Aug 27 2020 12:49:48 GMT: WARNING (socket): (socket.c:814) (repeated:40) Error while connecting socket to 10.10.1.193:3002
Aug 27 2020 12:49:48 GMT: INFO (scan): (scan.c:614) starting basic scan job 5387393483421091366 {test:location} priority 1, sample-pct 100, fail-on-cluster-change
Aug 27 2020 12:49:49 GMT: INFO (scan): (scan.c:692) finished basic scan job 5387393483421091366 (0)
Aug 27 2020 12:49:55 GMT: INFO (nsup): (thr_sindex.c:493) {test} sindex-gc start
Aug 27 2020 12:49:56 GMT: INFO (nsup): (thr_sindex.c:524) {test} sindex-gc: Processed: 2039, found:0, deleted: 0: Total time: 968 ms
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:171) NODE-ID bb9381648f12802 CLUSTER-SIZE 1
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:247)    cluster-clock: skew-ms 0
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:277)    system-memory: free-kbytes 8000148 free-pct 97 heap-kbytes (2184042,2186496,2301952) heap-efficiency-pct 94.9
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:291)    in-progress: tsvc-q 0 info-q 0 nsup-delete-q 0 rw-hash 0 proxy-hash 0 tree-gc-q 0
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:313)    fds: proto (3,2971455,2971452) heartbeat (0,13,13) fabric (2,60,58)
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:322)    heartbeat-received: self 0 foreign 0
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:353)    fabric-bytes-per-second: bulk (0,0) ctrl (0,0) meta (0,0) rw (0,0)
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:408) {test} objects: all 1370 master 1370 prole 0 non-replica 0
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:469) {test} migrations: complete
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:488) {test} memory-usage: total-bytes 852403 index-bytes 87680 sindex-bytes 304732 data-bytes 459991 used-pct 0.02
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:518) {test} device-usage: used-bytes 495104 avail-pct 99
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:587) {test} client: tsvc (0,0) proxy (0,0,0) read (89908,0,0,15569) write (38392,0,0) delete (951,0,0,3) udf (0,0,0) lang (0,0,0,0)
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:667) {test} scan: basic (42739,0,0) aggr (0,0,0) udf-bg (2,0,0)
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:692) {test} query: basic (50746,0) aggr (0,0) udf-bg (0,0)
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:720) {test} udf-sub: tsvc (0,0) udf (3,0,0) lang (3,0,0,0)
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:240) histogram dump: {test}-read (105477 total) msec
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:257)  (00: 0000105365) (01: 0000000002) (02: 0000000001) (03: 0000000002)
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:257)  (04: 0000000022) (05: 0000000036) (06: 0000000040) (07: 0000000009)
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:240) histogram dump: {test}-write (38392 total) msec
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:257)  (00: 0000038278) (01: 0000000002) (02: 0000000001) (03: 0000000001)
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:257)  (04: 0000000040) (05: 0000000032) (06: 0000000030) (07: 0000000008)
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:240) histogram dump: {test}-query (50746 total) msec
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:257)  (00: 0000044668) (01: 0000000270) (02: 0000000661) (03: 0000001533)
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:257)  (04: 0000002224) (05: 0000000951) (06: 0000000414) (07: 0000000025)
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:240) histogram dump: {test}-query-rec-count (24048 total) count
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:257)  (01: 0000002418) (02: 0000011993) (03: 0000005168) (04: 0000004098)
Aug 27 2020 12:49:58 GMT: INFO (info): (hist.c:266)  (05: 0000000371)
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:408) {bar} objects: all 1 master 1 prole 0 non-replica 0
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:469) {bar} migrations: complete
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:488) {bar} memory-usage: total-bytes 87 index-bytes 64 sindex-bytes 0 data-bytes 23 used-pct 0.00
Aug 27 2020 12:49:58 GMT: INFO (info): (ticker.c:518) {bar} device-usage: used-bytes 64 avail-pct 99
Aug 27 2020 12:49:58 GMT: WARNING (socket): (socket.c:746) (repeated:39) Timeout while connecting
Aug 27 2020 12:49:58 GMT: WARNING (hb): (hb.c:4845) (repeated:39) could not create heartbeat connection to node {10.10.1.193:3002}
Aug 27 2020 12:49:58 GMT: WARNING (socket): (socket.c:814) (repeated:39) Error while connecting socket to 10.10.1.193:3002
Aug 27 2020 12:50:04 GMT: WARNING (socket): (socket.c:720) Error while connecting: 101 (Network is unreachable)
Aug 27 2020 12:50:05 GMT: INFO (drv_ssd): (drv_ssd.c:2134) {bar} /opt/aerospike/data/bar.dat: used-bytes 64 free-wblocks 16374 write-q 0 write (0,0.0) defrag-q 0 defrag-read (1,0.0) defrag-write (0,0.0)
Aug 27 2020 12:50:05 GMT: INFO (nsup): (thr_sindex.c:493) {test} sindex-gc start
Aug 27 2020 12:50:05 GMT: WARNING (info): (thr_info.c:4626) No network interface addresses detected for client access
Aug 27 2020 12:50:06 GMT: INFO (nsup): (thr_sindex.c:524) {test} sindex-gc: Processed: 2039, found:0, deleted: 0: Total time: 977 ms
Aug 27 2020 12:50:06 GMT: INFO (as): (signal.c:194) SIGTERM received, starting normal shutdown
Aug 27 2020 12:50:06 GMT: INFO (storage): (storage.c:702) initiating storage shutdown ...
Aug 27 2020 12:50:06 GMT: INFO (storage): (storage.c:703) flushing data to storage ...
Aug 27 2020 12:50:07 GMT: INFO (storage): (storage.c:722) completed flushing to storage
Aug 27 2020 12:50:07 GMT: INFO (as): (as.c:445) finished clean shutdown - exiting

It is stuck while starting itself.

I do have a log for aerospike loader.

ERROR AerospikeLoad    :244  - com.aerospike.client.AerospikeException$Connection: Error Code -8: Failed to connect to host(s): 
127.0.0.1 3000 Error Code -8: java.net.ConnectException: Connection refused (Connection refused)

INFO  AerospikeLoad    :251  - Aerospike loader completed
INFO  AerospikeLoad    :258  - Loader completed in 0.097sec
4

Seems there is some sort of watchdog shutting down the asd daemon:

Aug 27 2020 12:50:06 GMT: INFO (as): (signal.c:194) SIGTERM received, starting normal shutdown
2 Likes
5

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