downstream_timeout does not work on moxi
I start moxi like this, we are connecting to membase server
/usr/local/sbin/moxi -Z cycle=100,wait_queue_timeout=100,downstream_timeout=100 -u www -d -P /var/run/moxi.pid http://192.168.6.143:8091/pools/default/bucketsStreaming/default,http://192.168.6.102:8091/pools/default/bucketsStreaming/default
yet when we start sending connections, from time to time we are getting response times of up to 10 seconds! So it is clear the downstream_timeout option does not work, please help me figure out what am I doing wrong.
thank you for your answer, I really appreciate that, here is the output
STAT basic:version 1.6.4.1
STAT basic:nthreads 5
STAT basic:hostname xxx
STAT memcached:settings:maxbytes 67108864
STAT memcached:settings:maxconns 1024
STAT memcached:settings:tcpport -2
STAT memcached:settings:udpport -2
STAT memcached:settings:inter NULL
STAT memcached:settings:verbosity 0
STAT memcached:settings:oldest 0
STAT memcached:settings:evictions on
STAT memcached:settings:domain_socket NULL
STAT memcached:settings:umask 700
STAT memcached:settings:growth_factor 1.25
STAT memcached:settings:chunk_size 48
STAT memcached:settings:num_threads 5
STAT memcached:settings:stat_key_prefix :
STAT memcached:settings:detail_enabled no
STAT memcached:settings:reqs_per_event 20
STAT memcached:settings:cas_enabled yes
STAT memcached:settings:tcp_backlog 1024
STAT memcached:settings:binding_protocol auto-negotiate
STAT memcached:stats:pid 83030
STAT memcached:stats:uptime 82840
STAT memcached:stats:time 1295893835
STAT memcached:stats:version 1.6.4.1
STAT memcached:stats:pointer_size 64
STAT memcached:stats:rusage_user 10069.709329
STAT memcached:stats:rusage_system 14566.957599
STAT memcached:stats:curr_connections 327
STAT memcached:stats:total_connections 18104451
STAT memcached:stats:connection_structures 435
STAT memcached:stats:cmd_get 0
STAT memcached:stats:cmd_set 0
STAT memcached:stats:cmd_flush 0
STAT memcached:stats:get_hits 0
STAT memcached:stats:get_misses 0
STAT memcached:stats:delete_misses 0
STAT memcached:stats:delete_hits 0
STAT memcached:stats:incr_misses 0
STAT memcached:stats:incr_hits 0
STAT memcached:stats:decr_misses 0
STAT memcached:stats:decr_hits 0
STAT memcached:stats:cas_misses 0
STAT memcached:stats:cas_hits 0
STAT memcached:stats:cas_badval 0
STAT memcached:stats:bytes_read 113291458204
STAT memcached:stats:bytes_written 63015796611
STAT memcached:stats:limit_maxbytes 67108864
STAT memcached:stats:accepting_conns 1
STAT memcached:stats:listen_disabled_num 0
STAT memcached:stats:threads 5
STAT memcached:stats:conn_yields 0
STAT proxy_main:conf_type dynamic
STAT proxy_main:behavior:cycle 100
STAT proxy_main:behavior:downstream_max 4
STAT proxy_main:behavior:downstream_conn_max 0
STAT proxy_main:behavior:downstream_weight 0
STAT proxy_main:behavior:downstream_retry 1
STAT proxy_main:behavior:downstream_protocol 8
STAT proxy_main:behavior:downstream_timeout 100
STAT proxy_main:behavior:downstream_conn_queue_timeout 0
STAT proxy_main:behavior:connect_timeout 5000
STAT proxy_main:behavior:auth_timeout 0
STAT proxy_main:behavior:wait_queue_timeout 100
STAT proxy_main:behavior:time_stats 0
STAT proxy_main:behavior:connect_max_errors 0
STAT proxy_main:behavior:connect_retry_interval 0
STAT proxy_main:behavior:front_cache_max 200
STAT proxy_main:behavior:front_cache_lifespan 0
STAT proxy_main:behavior:front_cache_spec
STAT proxy_main:behavior:front_cache_unspec
STAT proxy_main:behavior:key_stats_max 4000
STAT proxy_main:behavior:key_stats_lifespan 0
STAT proxy_main:behavior:key_stats_spec
STAT proxy_main:behavior:key_stats_unspec
STAT proxy_main:behavior:optimize_set
STAT proxy_main:behavior:usr
STAT proxy_main:behavior:host
STAT proxy_main:behavior:port 0
STAT proxy_main:behavior:bucket
STAT proxy_main:behavior:port_listen 11211
STAT proxy_main:behavior:default_bucket_name [ <FIRST_BUCKET> ]
STAT proxy_main:stats:stat_configs 1
STAT proxy_main:stats:stat_config_fails 0
STAT proxy_main:stats:stat_proxy_starts 1
STAT proxy_main:stats:stat_proxy_start_fails 0
STAT proxy_main:stats:stat_proxy_existings 0
STAT proxy_main:stats:stat_proxy_shutdowns 0
STAT 11211:default:info:port 11211
STAT 11211:default:info:name default
STAT 11211:default:info:config 192.168.6.102:11210,192.168.6.143:11210
STAT 11211:default:info:config_ver 1
STAT 11211:default:info:behaviors_num 2
STAT 11211:default:behavior:downstream_max 4
STAT 11211:default:behavior:downstream_conn_max 0
STAT 11211:default:behavior:downstream_weight 0
STAT 11211:default:behavior:downstream_retry 1
STAT 11211:default:behavior:downstream_protocol 8
STAT 11211:default:behavior:downstream_timeout 100
STAT 11211:default:behavior:downstream_conn_queue_timeout 0
STAT 11211:default:behavior:connect_timeout 5000
STAT 11211:default:behavior:auth_timeout 0
STAT 11211:default:behavior:wait_queue_timeout 100
STAT 11211:default:behavior:time_stats 0
STAT 11211:default:behavior:connect_max_errors 0
STAT 11211:default:behavior:connect_retry_interval 0
STAT 11211:default:behavior:front_cache_max 200
STAT 11211:default:behavior:front_cache_lifespan 0
STAT 11211:default:behavior:front_cache_spec
STAT 11211:default:behavior:front_cache_unspec
STAT 11211:default:behavior:key_stats_max 4000
STAT 11211:default:behavior:key_stats_lifespan 0
STAT 11211:default:behavior:key_stats_spec
STAT 11211:default:behavior:key_stats_unspec
STAT 11211:default:behavior:optimize_set
STAT 11211:default:behavior:usr default
STAT 11211:default:behavior:host
STAT 11211:default:behavior:port 0
STAT 11211:default:behavior:bucket
STAT 11211:default:behavior:port_listen 11211
STAT 11211:default:behavior:default_bucket_name [ <FIRST_BUCKET> ]
STAT 11211:default:behavior-0:downstream_weight 0
STAT 11211:default:behavior-0:downstream_retry 1
STAT 11211:default:behavior-0:downstream_protocol 8
STAT 11211:default:behavior-0:downstream_timeout 100
STAT 11211:default:behavior-0:downstream_conn_queue_timeout 0
STAT 11211:default:behavior-0:connect_timeout 5000
STAT 11211:default:behavior-0:auth_timeout 0
STAT 11211:default:behavior-0:usr default
STAT 11211:default:behavior-0:host 192.168.6.102
STAT 11211:default:behavior-0:port 11210
STAT 11211:default:behavior-0:bucket
STAT 11211:default:behavior-1:downstream_weight 0
STAT 11211:default:behavior-1:downstream_retry 1
STAT 11211:default:behavior-1:downstream_protocol 8
STAT 11211:default:behavior-1:downstream_timeout 100
STAT 11211:default:behavior-1:downstream_conn_queue_timeout 0
STAT 11211:default:behavior-1:connect_timeout 5000
STAT 11211:default:behavior-1:auth_timeout 0
STAT 11211:default:behavior-1:usr default
STAT 11211:default:behavior-1:host 192.168.6.143
STAT 11211:default:behavior-1:port 11210
STAT 11211:default:behavior-1:bucket
STAT 11211:default:stats:listening 2
STAT 11211:default:stats:listening_failed 0
STAT 11211:default:frontcache:max 0
STAT 11211:default:frontcache:oldest_live 0
STAT 11211:default:frontcache:tot_get_hits 0
STAT 11211:default:frontcache:tot_get_expires 0
STAT 11211:default:frontcache:tot_get_misses 0
STAT 11211:default:frontcache:tot_get_bytes 0
STAT 11211:default:frontcache:tot_adds 0
STAT 11211:default:frontcache:tot_add_skips 0
STAT 11211:default:frontcache:tot_add_fails 0
STAT 11211:default:frontcache:tot_add_bytes 0
STAT 11211:default:frontcache:tot_deletes 0
STAT 11211:default:frontcache:tot_evictions 0
STAT 11211:default:pstd_stats:num_upstream 294
STAT 11211:default:pstd_stats:tot_upstream 18101831
STAT 11211:default:pstd_stats:num_downstream_conn 32
STAT 11211:default:pstd_stats:tot_downstream_conn 2618
STAT 11211:default:pstd_stats:tot_downstream_conn_acquired 245057545
STAT 11211:default:pstd_stats:tot_downstream_conn_released 245054953
STAT 11211:default:pstd_stats:tot_downstream_released 245057555
STAT 11211:default:pstd_stats:tot_downstream_reserved 245057545
STAT 11211:default:pstd_stats:tot_downstream_reserved_time 0
STAT 11211:default:pstd_stats:max_downstream_reserved_time 0
STAT 11211:default:pstd_stats:tot_downstream_freed 0
STAT 11211:default:pstd_stats:tot_downstream_quit_server 2586
STAT 11211:default:pstd_stats:tot_downstream_max_reached 4087591
STAT 11211:default:pstd_stats:tot_downstream_create_failed 0
STAT 11211:default:pstd_stats:tot_downstream_connect_started 2618
STAT 11211:default:pstd_stats:tot_downstream_connect_wait 2615
STAT 11211:default:pstd_stats:tot_downstream_connect 2618
STAT 11211:default:pstd_stats:tot_downstream_connect_failed 0
STAT 11211:default:pstd_stats:tot_downstream_connect_timeout 0
STAT 11211:default:pstd_stats:tot_downstream_connect_interval 0
STAT 11211:default:pstd_stats:tot_downstream_connect_max_reached 0
STAT 11211:default:pstd_stats:tot_downstream_waiting_errors 0
STAT 11211:default:pstd_stats:tot_downstream_auth 2618
STAT 11211:default:pstd_stats:tot_downstream_auth_failed 0
STAT 11211:default:pstd_stats:tot_downstream_bucket 2618
STAT 11211:default:pstd_stats:tot_downstream_bucket_failed 0
STAT 11211:default:pstd_stats:tot_downstream_propagate_failed 0
STAT 11211:default:pstd_stats:tot_downstream_close_on_upstream_close 0
STAT 11211:default:pstd_stats:tot_downstream_conn_queue_timeout 0
STAT 11211:default:pstd_stats:tot_downstream_conn_queue_add 0
STAT 11211:default:pstd_stats:tot_downstream_conn_queue_remove 0
STAT 11211:default:pstd_stats:tot_downstream_timeout 2586
STAT 11211:default:pstd_stats:tot_wait_queue_timeout 25072
STAT 11211:default:pstd_stats:tot_auth_timeout 0
STAT 11211:default:pstd_stats:tot_assign_downstream 245057545
STAT 11211:default:pstd_stats:tot_assign_upstream 245057545
STAT 11211:default:pstd_stats:tot_assign_recursion 0
STAT 11211:default:pstd_stats:tot_reset_upstream_avail 0
STAT 11211:default:pstd_stats:tot_multiget_keys 0
STAT 11211:default:pstd_stats:tot_multiget_keys_dedupe 0
STAT 11211:default:pstd_stats:tot_multiget_bytes_dedupe 0
STAT 11211:default:pstd_stats:tot_optimize_sets 0
STAT 11211:default:pstd_stats:tot_optimize_self 0
STAT 11211:default:pstd_stats:tot_retry 0
STAT 11211:default:pstd_stats:tot_retry_time 0
STAT 11211:default:pstd_stats:max_retry_time 0
STAT 11211:default:pstd_stats:tot_retry_vbucket 0
STAT 11211:default:pstd_stats:tot_upstream_paused 245082617
STAT 11211:default:pstd_stats:tot_upstream_unpaused 245082611
STAT 11211:default:pstd_stats:err_oom 0
STAT 11211:default:pstd_stats:err_upstream_write_prep 0
STAT 11211:default:pstd_stats:err_downstream_write_prep 0
STAT 11211:default:pstd_stats_cmd:regular_get:seen 232057596
STAT 11211:default:pstd_stats_cmd:regular_get_key:hits 219031917
STAT 11211:default:pstd_stats_cmd:regular_get_key:write_bytes 29947026850
STAT 11211:default:pstd_stats_cmd:regular_add:seen 13025021
STAT 11211:default:pstd_stats_cmd:regular_add:read_bytes 7054415466
STAT 11211:default:pstd_stats_cmd:regular_quit:seen 18101537
STAT 11211:default:pstd_stats_cmd:regular_quit:read_bytes 72406148
END
Hi,
Thanks! The quick counters I was looking for in that show that various timeouts are getting fired...
STAT 11211:default:pstd_stats:tot_downstream_timeout 2586
STAT 11211:default:pstd_stats:tot_wait_queue_timeout 25072
Are you regularly seeing super long timeouts?
Steve
On some small % of connections we see that it takes up to 10 seconds for membase server to respond. It is some really small % but NOT meaningless to us. We thought we will mitigate this by using timeout, but timout settigns in moxi does not work for us!! Is there anything we can do to troubleshoot this issue?
Hi,
Apologies -- I noticed just now you also had not defined a "downstream_conn_queue_timeout", and I should have saw that earlier. This means there won't be a timeout response if a request is just waiting for a specific downstream connection. I'm hopeful that is the case here.
For more info on the downstream_conn_queue_timeout and other queues & timeouts in moxi, please see this page: http://wiki.membase.org/display/membase/Follow+A+Request+Through+Moxi
Cheers,
Steve
Hi, can you provide the output of "stats proxy" from that moxi? I tend to use "echo stats proxy | nc HOST 11211"
Thanks,
steve