Hi All,
I am using replication on 2 node setup with client write policy set to AS_POLICY_COMMIT_LEVEL_ALL.
Total timeout on client is set to 0 so I guess transaction-max-ns (which defaults to 1 sec) would be honored on server side. On client side I see timeout errors.
E1122 11:15:34.175964 61 AeroOps.cpp:203] WriteListener::error msg:AEROSPIKE_ERR_TIMEOUT, err code:9
Tried to get sense of context in which timeout could be happening.
Admin> show statistics like timeout
~~~~~~~~~Service Statistics (2019-11-22 16:18:50 UTC)~~~~~~~~
NODE : 192.168.4.227:3000 192.168.4.27:3000
batch_index_timeout: 0 0
batch_timeout : 0 0
~~~~~~~CLEAN Namespace Statistics (2019-11-22 16:18:50 UTC)~~~~~~
NODE : 192.168.4.227:3000 192.168.4.27:3000
batch_sub_proxy_timeout: 0 0
batch_sub_read_timeout : 0 0
batch_sub_tsvc_timeout : 0 0
client_delete_timeout : 0 0
client_proxy_timeout : 0 0
client_read_timeout : 0 0
client_tsvc_timeout : 0 0
client_udf_timeout : 0 0
client_write_timeout : 797 0
re_repl_timeout : 0 0
udf_sub_tsvc_timeout : 0 0
udf_sub_udf_timeout : 0 0
xdr_delete_timeout : 0 0
xdr_write_timeout : 0 0
~~~~~~~DIRTY Namespace Statistics (2019-11-22 16:18:50 UTC)~~~~~~
NODE : 192.168.4.227:3000 192.168.4.27:3000
batch_sub_proxy_timeout: 0 0
batch_sub_read_timeout : 0 0
batch_sub_tsvc_timeout : 0 0
client_delete_timeout : 0 0
client_proxy_timeout : 0 0
client_read_timeout : 0 0
client_tsvc_timeout : 0 0
client_udf_timeout : 0 0
client_write_timeout : 599 37
re_repl_timeout : 0 0
udf_sub_tsvc_timeout : 0 0
udf_sub_udf_timeout : 0 0
xdr_delete_timeout : 0 0
xdr_write_timeout : 0 0
Admin>
I see some writes got succeeded though.
~~~~~~~~~~~~~DIRTY Namespace Statistics (2019-11-22 14:57:19 UTC)~~~~~~~~~~~~
NODE : 192.168.4.227:3000 192.168.4.27:3000
allow-nonxdr-writes : true true
allow-xdr-writes : true true
client_lang_write_success : 0 0
client_write_error : 0 0
client_write_success : 2292 73
client_write_timeout : 530 12
Whats does client_write_timeout stands for?
Any configuration option to handle it?
Why writes are not distributed evenly across 2 nodes?
I enabled debug logs for fabric but couldn’t confirm if these are replica write failures.
Thanks,
Mahaveer
meher
November 22, 2019, 9:49pm
2
My (wild) guess would be for issues / latency between the 2 nodes and maybe connectivity issues between the client and one of the node. Looking at the logs and the configuration should provide more insight.
kporter
November 22, 2019, 10:08pm
3
These are writes (puts) from the client that resulted in a timeout.
Writes for a particular record are always sent to the node acting as master for a the partition that record belongs to. Likely the client_write_success
imbalance is due to a hot record.
Hi Meher & Kevin,
Thanks for prompt response.
Admin> show statistics like fd
~~~~Service Statistics (2019-11-23 01:47:17 UTC)~~~~
NODE : 192.168.4.227:3000 192.168.4.27:3000
reaped_fds: 10337 504
Admin> root@photon-machine:/# asloglatency -f head -t 600 -n 10 -e 1 -N DIRTY -h write
Histogram : {DIRTY}-write
Log : /var/log/aerospike/aerospike.log
From : 2019-11-22 11:04:14
Nov 22 2019 11:16:55
% > (ms)
slice-to (sec) 1 2 4 8 16 32 64 128 256 512 ops/sec
-------------- ------ ------ ------ ------ ------ ------ ------ ------ ------ ------ ----------
11:26:55 600 99.77 34.41 4.85 2.31 1.39 0.46 0.00 0.00 0.00 0.00 0.7
11:36:56 601 98.75 37.50 16.25 8.13 4.38 2.08 0.42 0.00 0.00 0.00 0.8
11:46:56 600 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.0
11:56:56 600 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.0
12:06:56 600 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.0
12:16:56 600 100.00 48.83 16.63 7.89 4.48 2.13 0.85 0.00 0.00 0.00 0.8
12:26:57 601 99.13 44.47 12.15 3.47 1.08 0.65 0.00 0.00 0.00 0.00 0.8
12:36:57 600 98.36 36.44 11.51 4.93 1.64 1.64 1.37 0.00 0.00 0.00 0.6
In non-cluster mode, I don’t see timeouts.
Which logs should be looked into?
Any config option changes which can be tried out?
In case of replication, which CONTEXT to enable debug logs for? So far I’ve tried socket, rw, fabric.
Thanks.
pgupta
November 23, 2019, 7:12am
5
You might want to enable write microbenchmakrs and look for write-repl-write in aerospike.log in the clustered mode:
asinfo -v 'set-config:context=namespace;id=DIRTY;enable-benchmarks-write=true'
Log-analyzer> histogram -h write-repl-write -N DIRTY -b 8 -d 900 -f -14500 -p 100
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~DIRTY - write-repl-write Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
NODE : bcc6e4f99565000 . . . . . . |
. : % >1ms % >8ms % >64ms % >512ms % >4096ms % >32768ms ops/sec |
Nov 23 2019 03:04:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:00: 90.00 0.00 0.00 0.00 0.00 0.00 3.0 |
Nov 23 2019 03:05:10: 96.03 5.56 0.00 0.00 0.00 0.00 12.6 |
Nov 23 2019 03:05:20: 98.82 5.88 0.00 0.00 0.00 0.00 8.5 |
Nov 23 2019 03:05:30: 100.00 10.53 5.26 0.00 0.00 0.00 3.8 |
Nov 23 2019 03:05:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Does it mean NW between cluster nodes is slow?
Any configuration option to increase efficiency?
pgupta
November 23, 2019, 7:30am
7
Here is the write path pre ver 4.7. Mostly still the same. Look at all other microbenchmarks and identify the source of the latency. They are all captured once you turn the write microbenchmark on. Confirm - write-repl-write is dominant source.
Thanks for help.
Still I’ve few queries.
How to get fabric network connection performance numbers?
Parameters to look into NIC configuration from aerospike point of view?
Here is the log of all the micro-bench-marking for write.
Log-analyzer> histogram -h write-start -N DIRTY -b 8 -d 250 -f -14300 -p 100
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~DIRTY - write-start Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
NODE : bcc6e4f99565000 . . . . . . |
. : % >1ms % >8ms % >64ms % >512ms % >4096ms % >32768ms ops/sec |
Nov 23 2019 03:02:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:00: 0.00 0.00 0.00 0.00 0.00 0.00 3.8 |
Nov 23 2019 03:05:10: 2.58 0.65 0.00 0.00 0.00 0.00 15.5 |
Nov 23 2019 03:05:20: 1.92 0.00 0.00 0.00 0.00 0.00 10.4 |
Nov 23 2019 03:05:30: 0.00 0.00 0.00 0.00 0.00 0.00 4.5 |
Nov 23 2019 03:05:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
avg : 0.19 0.03 0.00 0.00 0.00 0.00 1.0 |
max : 2.58 0.65 0.00 0.00 0.00 0.00 15.5 |
Log-analyzer> histogram -h write-repl-write -N DIRTY -b 8 -d 250 -f -14300 -p 100
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~DIRTY - write-repl-write Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
NODE : bcc6e4f99565000 . . . . . . |
. : % >1ms % >8ms % >64ms % >512ms % >4096ms % >32768ms ops/sec |
Nov 23 2019 03:02:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:00: 90.00 0.00 0.00 0.00 0.00 0.00 3.0 |
Nov 23 2019 03:05:10: 96.03 5.56 0.00 0.00 0.00 0.00 12.6 |
Nov 23 2019 03:05:20: 98.82 5.88 0.00 0.00 0.00 0.00 8.5 |
Nov 23 2019 03:05:30: 100.00 10.53 5.26 0.00 0.00 0.00 3.8 |
Nov 23 2019 03:05:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
avg : 16.04 0.92 0.22 0.00 0.00 0.00 1.0 |
max : 100.00 10.53 5.26 0.00 0.00 0.00 12.6 |
Log-analyzer> histogram -h write-dup-res -N DIRTY -b 8 -d 250 -f -14300 -p 100
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~DIRTY - write-dup-res Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
NODE : bcc6e4f99565000 . . . . . . |
. : % >1ms % >8ms % >64ms % >512ms % >4096ms % >32768ms ops/sec |
Nov 23 2019 03:02:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
avg : 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
max : 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Log-analyzer> histogram -h write-master -N DIRTY -b 8 -d 250 -f -14300 -p 100
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~DIRTY - write-master Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
NODE : bcc6e4f99565000 . . . . . . |
. : % >1ms % >8ms % >64ms % >512ms % >4096ms % >32768ms ops/sec |
Nov 23 2019 03:02:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:00: 5.26 5.26 0.00 0.00 0.00 0.00 3.8 |
Nov 23 2019 03:05:10: 2.58 1.94 0.00 0.00 0.00 0.00 15.5 |
Nov 23 2019 03:05:20: 0.00 0.00 0.00 0.00 0.00 0.00 10.4 |
Nov 23 2019 03:05:30: 0.00 0.00 0.00 0.00 0.00 0.00 4.5 |
Nov 23 2019 03:05:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
avg : 0.33 0.30 0.00 0.00 0.00 0.00 1.0 |
max : 5.26 5.26 0.00 0.00 0.00 0.00 15.5 |
Log-analyzer> histogram -h write-restart -N DIRTY -b 8 -d 250 -f -14300 -p 100
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~DIRTY - write-restart Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
NODE : bcc6e4f99565000 . . . . . . |
. : % >1ms % >8ms % >64ms % >512ms % >4096ms % >32768ms ops/sec |
Nov 23 2019 03:02:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
avg : 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
max : 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Log-analyzer> histogram -h write-response -N DIRTY -b 8 -d 250 -f -14300 -p 100
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~DIRTY - write-response Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
NODE : bcc6e4f99565000 . . . . . . |
. : % >1ms % >8ms % >64ms % >512ms % >4096ms % >32768ms ops/sec |
Nov 23 2019 03:02:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:02:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:03:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:30: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:04:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:00: 0.00 0.00 0.00 0.00 0.00 0.00 3.0 |
Nov 23 2019 03:05:10: 0.00 0.00 0.00 0.00 0.00 0.00 12.6 |
Nov 23 2019 03:05:20: 1.18 0.00 0.00 0.00 0.00 0.00 8.5 |
Nov 23 2019 03:05:30: 0.00 0.00 0.00 0.00 0.00 0.00 3.8 |
Nov 23 2019 03:05:40: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:05:50: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:00: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:10: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
Nov 23 2019 03:06:20: 0.00 0.00 0.00 0.00 0.00 0.00 0.0 |
avg : 0.05 0.00 0.00 0.00 0.00 0.00 1.0 |
max : 1.18 0.00 0.00 0.00 0.00 0.00 12.6 |
Log-analyzer>
pgupta
November 23, 2019, 4:56pm
11
Fabric has its own microbenchmarks that you can turn on. Read more here - in fabric transaction analysis: https://www.aerospike.com/docs/operations/monitor/latency/index.html
If you had hot-key writes, you will see high write-restart total count in the logs, grep for write-restart and it will show you total count - and latency data. The histograms are computed from those raw counts.
What’s interesting is that you have a few high write-master also. What is your configuration for this namespace in the aeropsike.conf file? What is your server version?
I see some high write-response numbers too. That means the socket send buffer is getting full because of a slow network connection to the client. Looks like you definitely have some network issues.