twitter / twemproxy

A fast, light-weight proxy for memcached and redis
Apache License 2.0
12.13k stars 2.06k forks source link

Twemproxy becomes unresponsive, doesn't respond to commands until restarted #433

Open sidprak opened 8 years ago

sidprak commented 8 years ago

Hello,

We just experienced an issue across multiple of our Twemproxy servers that caused them to hang and stop responding to Redis commands. The servers both started around the same time (if that matters) and both stopped responding within 30 seconds of each other. I was wondering if we could get some of your insight into what happened.

The server seemed to be operating normally, suddenly started consuming a lot of memory and got into a hung state where it didn't respond to any commands. It also didn't log anything during the time it was unavailable. We run automated monitoring on the backend Redis servers and we've verified that they were all alive and responding to commands during this time. The issue resolved itself when I restarted Twemproxy. The connection timed out message indicates that it may be a problem with the Redis server not responding in time but it is also odd that 1) the server was responding to our monitoring and 2) the issue resolved itself after restarting the proxy. Is there a certain Redis command that could cause something like this?

Configuration

redis_cluster:
  listen: 0.0.0.0:22111
  hash_tag: "{}"
  hash: fnv1a_64
  distribution: ketama
  timeout: 8000
  auto_eject_hosts: false
  preconnect: true
  redis: true
  servers:
    - ...

Twemproxy log

[Fri Nov 20 15:30:23 2015] nc_proxy.c:336 accepted c 313 on p 38 from '127.0.0.1:55683'
[Fri Nov 20 15:30:23 2015] nc_core.c:201 close c 313 '127.0.0.1:55683' on event FFFF eof 1 done 1 rb 0 sb 0
[Fri Nov 20 15:30:25 2015] nc_core.c:201 close c 355 '10.153.161.11:42144' on event 00FF eof 1 done 1 rb 9337489 sb 196610
[Fri Nov 20 15:30:25 2015] nc_proxy.c:336 accepted c 313 on p 38 from '127.0.0.1:55684'
[Fri Nov 20 15:30:25 2015] nc_core.c:201 close c 313 '127.0.0.1:55684' on event FFFF eof 1 done 1 rb 0 sb 0
[Fri Nov 20 15:30:27 2015] nc_proxy.c:336 accepted c 313 on p 38 from '127.0.0.1:55685'
[Fri Nov 20 15:30:27 2015] nc_core.c:201 close c 313 '127.0.0.1:55685' on event FFFF eof 1 done 1 rb 0 sb 0
[Fri Nov 20 15:30:30 2015] nc_proxy.c:336 accepted c 313 on p 38 from '127.0.0.1:55686'
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close c 313 '127.0.0.1:55686' on event FFFF eof 1 done 1 rb 0 sb 0
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 34 '10.81.147.121:16383' on event FFFF eof 0 done 0 rb 6500516968 sb 6597409394: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 7 '10.101.176.67:16397' on event FFFF eof 0 done 0 rb 16519790645 sb 8436631958: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 101 '10.101.176.67:16400' on event FFFF eof 0 done 0 rb 14482299157 sb 7437663567: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 8 '10.81.147.121:16394' on event FFFF eof 0 done 0 rb 7192546334 sb 2862473209: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 23 '10.81.147.121:16379' on event FFFF eof 0 done 0 rb 10140341308 sb 3541861302: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 25 '10.81.147.121:16390' on event FFFF eof 0 done 0 rb 6222270100 sb 2575703776: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 13 '10.101.176.67:16402' on event FFFF eof 0 done 0 rb 5656067711 sb 3208107440: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 29 '10.81.147.121:16392' on event FFFF eof 0 done 0 rb 16375822129 sb 7491696210: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 109 '10.101.176.67:16403' on event FFFF eof 0 done 0 rb 7033188937 sb 3165248734: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 20 '10.101.176.67:16405' on event FFFF eof 0 done 0 rb 5049494906 sb 2912358728: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 24 '10.101.176.67:16395' on event FFFF eof 0 done 0 rb 14582409223 sb 7437543343: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 11 '10.101.176.67:16398' on event FFFF eof 0 done 0 rb 8493865699 sb 3749516296: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 30 '10.101.176.67:16396' on event FFFF eof 0 done 0 rb 5690542864 sb 2879933765: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 35 '10.81.147.121:16389' on event FFFF eof 0 done 0 rb 9868206863 sb 11974818980: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 19 '10.101.176.67:16399' on event FFFF eof 0 done 0 rb 3640723229 sb 2266408893: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 22 '10.81.147.121:16380' on event FFFF eof 0 done 0 rb 2840311416 sb 2499551356: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 26 '10.101.176.67:16401' on event FFFF eof 0 done 0 rb 7856895940 sb 3450868310: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 18 '10.81.147.121:16382' on event FFFF eof 0 done 0 rb 7785360347 sb 3647852458: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 28 '10.101.176.67:16409' on event FFFF eof 0 done 0 rb 10876816017 sb 4636879042: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 14 '10.81.147.121:16391' on event FFFF eof 0 done 0 rb 5296392258 sb 2886882817: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 6 '10.81.147.121:16384' on event FFFF eof 0 done 0 rb 5529048908 sb 2391134191: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 17 '10.81.147.121:16387' on event FFFF eof 0 done 0 rb 6629604594 sb 3930064817: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 31 '10.101.176.67:16404' on event FFFF eof 0 done 0 rb 2684417151 sb 2525815006: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 33 '10.101.176.67:16406' on event FFFF eof 0 done 0 rb 13894211803 sb 6363319093: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 21 '10.81.147.121:16385' on event FFFF eof 0 done 0 rb 14175947919 sb 5886369400: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 37 '10.101.176.67:16407' on event FFFF eof 0 done 0 rb 7767051139 sb 2896583329: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 27 '10.81.147.121:16388' on event FFFF eof 0 done 0 rb 5308005719 sb 3467601963: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 9 '10.81.147.121:16381' on event FFFF eof 0 done 0 rb 56969140366 sb 17668770195: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 32 '10.81.147.121:16386' on event FFFF eof 0 done 0 rb 10626964628 sb 4409789478: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close s 12 '10.101.176.67:16408' on event 00FF eof 0 done 0 rb 8699313888 sb 3574219519: Connection timed out
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 7 on p 38 from '127.0.0.1:55687'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 8 on p 38 from '127.0.0.1:55688'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 9 on p 38 from '127.0.0.1:55689'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 11 on p 38 from '127.0.0.1:55690'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 12 on p 38 from '127.0.0.1:55691'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 13 on p 38 from '127.0.0.1:55692'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 14 on p 38 from '127.0.0.1:55693'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 17 on p 38 from '127.0.0.1:55694'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 18 on p 38 from '127.0.0.1:55695'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 19 on p 38 from '127.0.0.1:55696'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 20 on p 38 from '127.0.0.1:55697'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 21 on p 38 from '10.141.254.27:59567'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 22 on p 38 from '10.157.164.165:38110'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 23 on p 38 from '10.229.35.80:57003'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 24 on p 38 from '10.157.125.35:58347'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 25 on p 38 from '10.150.112.106:53063'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 26 on p 38 from '10.141.254.27:59570'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 27 on p 38 from '10.229.35.80:57010'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 28 on p 38 from '10.141.254.27:59571'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 29 on p 38 from '10.167.81.60:34398'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 30 on p 38 from '10.229.35.80:57013'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 31 on p 38 from '10.184.8.180:39252'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 32 on p 38 from '10.167.81.60:34399'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 33 on p 38 from '10.229.35.80:57014'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 34 on p 38 from '10.141.254.27:59574'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 35 on p 38 from '10.141.254.27:59575'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 37 on p 38 from '10.164.103.223:39581'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 101 on p 38 from '10.203.145.203:41854'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 109 on p 38 from '10.167.81.60:34400'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 313 on p 38 from '10.167.81.60:34401'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 318 on p 38 from '10.229.35.80:57019'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 349 on p 38 from '10.167.81.60:34402'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 351 on p 38 from '10.203.145.203:41855'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 352 on p 38 from '10.229.35.80:57020'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 354 on p 38 from '10.203.145.203:41856'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 355 on p 38 from '10.203.145.203:41857'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 357 on p 38 from '10.141.254.27:59576'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 358 on p 38 from '10.141.254.27:59577'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 359 on p 38 from '10.167.81.60:34403'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 363 on p 38 from '10.203.145.203:41860'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 365 on p 38 from '10.150.112.106:53066'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 370 on p 38 from '10.203.145.203:41863'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 376 on p 38 from '10.229.35.80:57021'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 377 on p 38 from '10.167.81.60:34404'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 378 on p 38 from '10.141.254.27:59578'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 379 on p 38 from '10.203.145.203:41864'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 380 on p 38 from '10.167.81.60:34405'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 381 on p 38 from '10.150.112.106:53067'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 382 on p 38 from '10.229.35.80:57022'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 383 on p 38 from '10.167.81.60:34406'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 384 on p 38 from '10.141.254.27:59579'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 385 on p 38 from '10.229.35.80:57023'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 386 on p 38 from '10.157.125.35:58349'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 387 on p 38 from '10.229.35.80:57024'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 389 on p 38 from '10.167.81.60:34407'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 391 on p 38 from '10.203.145.203:41912'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 392 on p 38 from '10.229.35.80:57025'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 393 on p 38 from '10.167.81.60:34410'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 394 on p 38 from '10.229.35.80:57026'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 395 on p 38 from '10.141.254.27:59580'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 396 on p 38 from '10.157.164.165:38112'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 397 on p 38 from '10.167.81.60:34411'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 398 on p 38 from '10.203.145.203:41913'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 399 on p 38 from '10.141.254.27:59581'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 400 on p 38 from '10.165.130.54:56135'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 401 on p 38 from '10.203.145.203:41914'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 402 on p 38 from '10.229.35.80:57029'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 403 on p 38 from '10.203.145.203:41915'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 404 on p 38 from '10.167.81.60:34412'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 405 on p 38 from '10.229.35.80:57030'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 406 on p 38 from '10.141.254.27:59582'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 407 on p 38 from '10.150.112.106:53068'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 408 on p 38 from '10.203.145.203:41918'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 409 on p 38 from '10.141.254.27:59583'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 411 on p 38 from '10.141.254.27:59584'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 412 on p 38 from '10.157.125.35:58350'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 413 on p 38 from '10.167.81.60:34413'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 414 on p 38 from '10.203.145.203:41919'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 415 on p 38 from '10.203.145.203:41920'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 416 on p 38 from '10.141.254.27:59587'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 417 on p 38 from '10.229.35.80:57031'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 418 on p 38 from '10.157.121.26:46460'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 419 on p 38 from '10.229.35.80:57032'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 420 on p 38 from '10.167.81.60:34418'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 421 on p 38 from '10.203.145.203:41923'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 422 on p 38 from '10.157.125.35:58351'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 423 on p 38 from '10.150.112.106:53071'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 424 on p 38 from '10.167.81.60:34419'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 425 on p 38 from '10.203.145.203:41924'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 426 on p 38 from '10.229.35.80:57033'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 427 on p 38 from '10.167.81.60:34422'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 428 on p 38 from '10.167.81.60:34423'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 429 on p 38 from '10.141.254.27:59588'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 430 on p 38 from '10.203.145.203:41927'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 431 on p 38 from '10.157.164.165:38114'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 432 on p 38 from '10.229.35.80:57038'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 433 on p 38 from '10.157.164.165:38115'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 434 on p 38 from '10.167.81.60:34424'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 435 on p 38 from '10.229.35.80:57039'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 436 on p 38 from '10.203.145.203:41928'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 437 on p 38 from '10.157.121.26:46467'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 438 on p 38 from '10.150.112.106:53072'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 439 on p 38 from '10.203.145.203:41929'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 440 on p 38 from '10.141.254.27:59591'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 441 on p 38 from '10.157.125.35:58354'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 442 on p 38 from '10.141.254.27:59592'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 443 on p 38 from '10.229.35.80:57040'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 444 on p 38 from '10.141.254.27:59593'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 445 on p 38 from '10.157.164.165:38119'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 446 on p 38 from '10.157.121.26:46470'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 447 on p 38 from '127.0.0.1:55698'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 448 on p 38 from '10.157.125.35:58357'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 449 on p 38 from '10.150.112.106:53075'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 450 on p 38 from '10.157.125.35:58358'
[Fri Nov 20 15:30:55 2015] nc_proxy.c:336 accepted c 451 on p 38 from '10.157.164.165:38125'
[Fri Nov 20 15:30:55 2015] nc_core.c:201 close c 175 '10.37.180.132:42442' on event FFFF eof 1 done 1 rb 70228199 sb 340403456

# Manually restarted #
[Fri Nov 20 15:57:44 2015] nc.c:187 nutcracker-0.3.0 built for Linux 3.13.0-36-generic x86_64 started on pid 5700
[Fri Nov 20 15:57:44 2015] nc.c:192 run, rabbit run / dig that hole, forget the sun / and when at last the work is done / don't sit down / it's time to dig another one

ps log

This is a list of ps entries for Nutcracker every minute during the window.

twemproxy       806  4.0 18.4 739108 709616 ?       Ssl  Nov03 1027:37  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 18.4 739108 709616 ?       Ssl  Nov03 1027:39  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1028:12  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1029:18  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1030:25  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1031:32  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1032:35  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1033:41  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1034:33  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1034:33  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1035:52  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1035:52  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1038:00  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.0 78.1 4896524 3000608 ?     Rsl  Nov03 1038:00  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1040:13  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1040:13  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1042:23  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1042:23  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1044:36  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1044:36  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1044:36  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1047:02  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1047:02  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1049:58  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1049:58  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1049:58  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1053:12  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1053:12  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy       806  4.1 78.1 4896524 3000608 ?     Rsl  Nov03 1053:12  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy      5700  6.0  0.1  30884  7640 ?        Ssl  15:57   0:01  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
twemproxy      5700  6.5  2.5 154192 97136 ?        Ssl  15:57   0:05  \_ /usr/sbin/nutcracker -c /etc/nutcracker/nutcracker.yml -o /var/log/nutcracker/nutcracker.log
TysonAndre commented 3 years ago

Not a maintainer - I've suspected https://github.com/twitter/twemproxy/pull/595 for a similar issue with memcached instead of redis but that seems almost certainly unrelated to the original issue - your use case has auto_eject_hosts: false and wouldn't be affected

It's almost certainly too late since this issue was filed in 2015, and this may have been fixed since then or the setup may have changed making this inactionable

Also, were pipelined requests used? That might explain a spike in cpu usage and memory usage due to other open issues reported for mbuf_split being inefficient, but the fact that the default small mbuf size is used makes that seem really unlikely

TysonAndre commented 3 years ago

This may be fixed by patches merged into twitter/twemproxy planned for 0.5.0