(twemproxy) nutcracker の冗長モードで起動した場合のログ [Sat Apr 26 21:16:33 2014] nc_stats.c:653 skip aggregate of shadow 0x2147230 to sum 0x2147730 as generator is slow
[Sat Apr 26 21:16:41 2014] nc_epoll.c:254 epoll 0001 triggered on conn 0x214b340
[Sat Apr 26 21:16:41 2014] nc_core.c:281 event 00FF on p 6
[Sat Apr 26 21:16:41 2014] nc_client.c:46 ref conn 0x214b4a0 owner 0x21422a0 into pool 'hoge'
[Sat Apr 26 21:16:41 2014] nc_connection.c:225 get conn 0x214b4a0 client 1
[Sat Apr 26 21:16:41 2014] nc_stats.c:1012 metric 'client_connections' in pool 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1029 incr field 'client_connections' to 1
[Sat Apr 26 21:16:41 2014] nc_proxy.c:336 accepted c 8 on p 6 from '127.0.0.1:58468'
[Sat Apr 26 21:16:41 2014] nc_proxy.c:280 accept on p 6 not ready - eagain
[Sat Apr 26 21:16:41 2014] nc_stats.c:980 swap stats current 0x2146e00 shadow 0x2147230
[Sat Apr 26 21:16:41 2014] nc_epoll.c:254 epoll 0005 triggered on conn 0x214b4a0
[Sat Apr 26 21:16:41 2014] nc_core.c:281 event FFFF on c 8
[Sat Apr 26 21:16:41 2014] nc_message.c:300 get msg 0x214b600 id 66 request 1 owner sd 8
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:99 get mbuf 0x214f770
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:182 insert mbuf 0x214f770 len 0
[Sat Apr 26 21:16:41 2014] nc_connection.c:324 recv on sd 8 21 of 16336
[Sat Apr 26 21:16:41 2014] nc_memcache.c:702 parsed req 66 res 0 type 5 state 0 rpos 21 of 21
00000000 73 65 74 20 74 65 73 74 20 30 20 30 20 33 0d 0a |set test 0 0 3..|
00000010 31 32 33 0d 0a |123..|
[Sat Apr 26 21:16:41 2014] nc_server.c:644 key 'test' on dist 0 maps to server 'xxx.xxx.x.164:11211:1'
[Sat Apr 26 21:16:41 2014] nc_message.c:165 insert msg 66 into tmo rbt with expiry of 100 msec
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'in_queue' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1130 incr field 'in_queue' to 1
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'in_queue_bytes' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1160 incr by field 'in_queue_bytes' to 21
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'requests' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1130 incr field 'requests' to 1
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'request_bytes' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1160 incr by field 'request_bytes' to 21
[Sat Apr 26 21:16:41 2014] nc_request.c:497 forward from c 8 to s 9 req 66 len 21 type 5 with key 'test'
[Sat Apr 26 21:16:41 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:41 2014] nc_epoll.c:254 epoll 0004 triggered on conn 0x214f7b0
[Sat Apr 26 21:16:41 2014] nc_core.c:281 event FF00 on s 9
[Sat Apr 26 21:16:41 2014] nc_request.c:558 send next req 66 len 21 type 5 on s 9
[Sat Apr 26 21:16:41 2014] nc_connection.c:375 sendv on sd 9 21 of 21 in 1 buffers
[Sat Apr 26 21:16:41 2014] nc_request.c:572 send done req 66 len 21 type 5 on s 9
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'in_queue' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1145 decr field 'in_queue' to 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'in_queue_bytes' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1175 decr by field 'in_queue_bytes' to 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'out_queue' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1130 incr field 'out_queue' to 1
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'out_queue_bytes' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1160 incr by field 'out_queue_bytes' to 21
[Sat Apr 26 21:16:41 2014] nc_epoll.c:254 epoll 0001 triggered on conn 0x214b4a0
[Sat Apr 26 21:16:41 2014] nc_core.c:281 event 00FF on c 8
[Sat Apr 26 21:16:41 2014] nc_message.c:300 get msg 0x214f910 id 67 request 1 owner sd 8
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:99 get mbuf 0x2153a80
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:182 insert mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:41 2014] nc_connection.c:324 recv on sd 8 0 of 16336
[Sat Apr 26 21:16:41 2014] nc_connection.c:338 recv on sd 8 eof rb 21 sb 0
[Sat Apr 26 21:16:41 2014] nc_request.c:371 filter empty req 67 from c 8
[Sat Apr 26 21:16:41 2014] nc_message.c:351 put msg 0x214f910 id 67
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:191 remove mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:121 put mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:41 2014] nc_client.c:76 c 8 is active
[Sat Apr 26 21:16:41 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:41 2014] nc_epoll.c:254 epoll 0001 triggered on conn 0x214f7b0
[Sat Apr 26 21:16:41 2014] nc_core.c:281 event 00FF on s 9
[Sat Apr 26 21:16:41 2014] nc_message.c:300 get msg 0x214f910 id 68 request 0 owner sd 9
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:99 get mbuf 0x2153a80
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:182 insert mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:41 2014] nc_connection.c:324 recv on sd 9 8 of 16336
[Sat Apr 26 21:16:41 2014] nc_memcache.c:1159 parsed rsp 68 res 0 type 14 state 0 rpos 8 of 8
00000000 53 54 4f 52 45 44 0d 0a |STORED..|
[Sat Apr 26 21:16:41 2014] nc_message.c:183 delete msg 66 from tmo rbt
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'out_queue' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1145 decr field 'out_queue' to 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'out_queue_bytes' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1175 decr by field 'out_queue_bytes' to 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'responses' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1130 incr field 'responses' to 1
[Sat Apr 26 21:16:41 2014] nc_stats.c:1113 metric 'response_bytes' in pool 0 server 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1160 incr by field 'response_bytes' to 8
[Sat Apr 26 21:16:41 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:41 2014] nc_epoll.c:254 epoll 0005 triggered on conn 0x214b4a0
[Sat Apr 26 21:16:41 2014] nc_core.c:281 event FFFF on c 8
[Sat Apr 26 21:16:41 2014] nc_client.c:76 c 8 is active
[Sat Apr 26 21:16:41 2014] nc_response.c:324 send next rsp 68 on c 8
[Sat Apr 26 21:16:41 2014] nc_connection.c:375 sendv on sd 8 8 of 8 in 1 buffers
[Sat Apr 26 21:16:41 2014] nc_response.c:337 send done rsp 68 on c 8
[Sat Apr 26 21:16:41 2014] nc_message.c:351 put msg 0x214f910 id 68
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:191 remove mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:121 put mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:41 2014] nc_message.c:351 put msg 0x214b600 id 66
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:191 remove mbuf 0x214f770 len 0
[Sat Apr 26 21:16:41 2014] nc_mbuf.c:121 put mbuf 0x214f770 len 0
[Sat Apr 26 21:16:41 2014] nc_response.c:284 c 8 is done
[Sat Apr 26 21:16:41 2014] nc_core.c:201 close c 8 '127.0.0.1:58468' on event FFFF eof 1 done 1 rb 21 sb 8
[Sat Apr 26 21:16:41 2014] nc_stats.c:1012 metric 'client_connections' in pool 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1044 decr field 'client_connections' to -1
[Sat Apr 26 21:16:41 2014] nc_stats.c:1012 metric 'client_eof' in pool 0
[Sat Apr 26 21:16:41 2014] nc_stats.c:1029 incr field 'client_eof' to 1
[Sat Apr 26 21:16:41 2014] nc_client.c:65 unref conn 0x214b4a0 owner 0x21422a0 from pool 'hoge'
[Sat Apr 26 21:16:41 2014] nc_connection.c:284 put conn 0x214b4a0
[Sat Apr 26 21:16:41 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:49 2014] nc_epoll.c:254 epoll 0001 triggered on conn 0x214b340
[Sat Apr 26 21:16:49 2014] nc_core.c:281 event 00FF on p 6
[Sat Apr 26 21:16:49 2014] nc_client.c:46 ref conn 0x214b4a0 owner 0x21422a0 into pool 'hoge'
[Sat Apr 26 21:16:49 2014] nc_connection.c:225 get conn 0x214b4a0 client 1
[Sat Apr 26 21:16:49 2014] nc_stats.c:1012 metric 'client_connections' in pool 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1029 incr field 'client_connections' to 0
[Sat Apr 26 21:16:49 2014] nc_proxy.c:336 accepted c 8 on p 6 from '127.0.0.1:58469'
[Sat Apr 26 21:16:49 2014] nc_proxy.c:280 accept on p 6 not ready - eagain
[Sat Apr 26 21:16:49 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:49 2014] nc_epoll.c:254 epoll 0004 triggered on conn 0x214b4a0
[Sat Apr 26 21:16:49 2014] nc_core.c:281 event FF00 on c 8
[Sat Apr 26 21:16:49 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:49 2014] nc_epoll.c:254 epoll 0001 triggered on conn 0x214b4a0
[Sat Apr 26 21:16:49 2014] nc_core.c:281 event 00FF on c 8
[Sat Apr 26 21:16:49 2014] nc_message.c:300 get msg 0x214b600 id 69 request 1 owner sd 8
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:99 get mbuf 0x214f770
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:182 insert mbuf 0x214f770 len 0
[Sat Apr 26 21:16:49 2014] nc_connection.c:324 recv on sd 8 8 of 16336
[Sat Apr 26 21:16:49 2014] nc_memcache.c:677 parsed req 69 res 4 type 1 state 3 rpos 8 of 8
00000000 67 65 74 20 74 65 73 74 |get test|
[Sat Apr 26 21:16:49 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:49 2014] nc_epoll.c:254 epoll 0001 triggered on conn 0x214b4a0
[Sat Apr 26 21:16:49 2014] nc_core.c:281 event 00FF on c 8
[Sat Apr 26 21:16:49 2014] nc_connection.c:324 recv on sd 8 2 of 16328
[Sat Apr 26 21:16:49 2014] nc_memcache.c:702 parsed req 69 res 0 type 1 state 0 rpos 10 of 10
00000000 67 65 74 20 74 65 73 74 0d 0a |get test..|
[Sat Apr 26 21:16:49 2014] nc_server.c:644 key 'test' on dist 0 maps to server 'xxx.xxx.x.164:11211:1'
[Sat Apr 26 21:16:49 2014] nc_message.c:165 insert msg 69 into tmo rbt with expiry of 100 msec
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'in_queue' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1130 incr field 'in_queue' to 1
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'in_queue_bytes' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1160 incr by field 'in_queue_bytes' to 10
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'requests' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1130 incr field 'requests' to 2
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'request_bytes' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1160 incr by field 'request_bytes' to 31
[Sat Apr 26 21:16:49 2014] nc_request.c:497 forward from c 8 to s 9 req 69 len 10 type 1 with key 'test'
[Sat Apr 26 21:16:49 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:49 2014] nc_epoll.c:254 epoll 0004 triggered on conn 0x214f7b0
[Sat Apr 26 21:16:49 2014] nc_core.c:281 event FF00 on s 9
[Sat Apr 26 21:16:49 2014] nc_request.c:558 send next req 69 len 10 type 1 on s 9
[Sat Apr 26 21:16:49 2014] nc_connection.c:375 sendv on sd 9 10 of 10 in 1 buffers
[Sat Apr 26 21:16:49 2014] nc_request.c:572 send done req 69 len 10 type 1 on s 9
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'in_queue' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1145 decr field 'in_queue' to 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'in_queue_bytes' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1175 decr by field 'in_queue_bytes' to 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'out_queue' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1130 incr field 'out_queue' to 1
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'out_queue_bytes' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1160 incr by field 'out_queue_bytes' to 10
[Sat Apr 26 21:16:49 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:49 2014] nc_epoll.c:254 epoll 0001 triggered on conn 0x214b4a0
[Sat Apr 26 21:16:49 2014] nc_core.c:281 event 00FF on c 8
[Sat Apr 26 21:16:49 2014] nc_message.c:300 get msg 0x214f910 id 70 request 1 owner sd 8
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:99 get mbuf 0x2153a80
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:182 insert mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:49 2014] nc_connection.c:324 recv on sd 8 0 of 16336
[Sat Apr 26 21:16:49 2014] nc_connection.c:338 recv on sd 8 eof rb 10 sb 0
[Sat Apr 26 21:16:49 2014] nc_request.c:371 filter empty req 70 from c 8
[Sat Apr 26 21:16:49 2014] nc_message.c:351 put msg 0x214f910 id 70
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:191 remove mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:121 put mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:49 2014] nc_client.c:76 c 8 is active
[Sat Apr 26 21:16:49 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:49 2014] nc_epoll.c:254 epoll 0001 triggered on conn 0x214f7b0
[Sat Apr 26 21:16:49 2014] nc_core.c:281 event 00FF on s 9
[Sat Apr 26 21:16:49 2014] nc_message.c:300 get msg 0x214f910 id 71 request 0 owner sd 9
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:99 get mbuf 0x2153a80
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:182 insert mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:49 2014] nc_connection.c:324 recv on sd 9 26 of 16336
[Sat Apr 26 21:16:49 2014] nc_memcache.c:1159 parsed rsp 71 res 0 type 19 state 0 rpos 26 of 26
00000000 56 41 4c 55 45 20 74 65 73 74 20 30 20 33 0d 0a |VALUE test 0 3..|
00000010 31 32 33 0d 0a 45 4e 44 0d 0a |123..END..|
[Sat Apr 26 21:16:49 2014] nc_message.c:183 delete msg 69 from tmo rbt
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'out_queue' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1145 decr field 'out_queue' to 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'out_queue_bytes' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1175 decr by field 'out_queue_bytes' to 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'responses' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1130 incr field 'responses' to 2
[Sat Apr 26 21:16:49 2014] nc_stats.c:1113 metric 'response_bytes' in pool 0 server 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1160 incr by field 'response_bytes' to 34
[Sat Apr 26 21:16:49 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
[Sat Apr 26 21:16:49 2014] nc_epoll.c:254 epoll 0005 triggered on conn 0x214b4a0
[Sat Apr 26 21:16:49 2014] nc_core.c:281 event FFFF on c 8
[Sat Apr 26 21:16:49 2014] nc_client.c:76 c 8 is active
[Sat Apr 26 21:16:49 2014] nc_response.c:324 send next rsp 71 on c 8
[Sat Apr 26 21:16:49 2014] nc_connection.c:375 sendv on sd 8 26 of 26 in 1 buffers
[Sat Apr 26 21:16:49 2014] nc_response.c:337 send done rsp 71 on c 8
[Sat Apr 26 21:16:49 2014] nc_message.c:351 put msg 0x214f910 id 71
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:191 remove mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:121 put mbuf 0x2153a80 len 0
[Sat Apr 26 21:16:49 2014] nc_message.c:351 put msg 0x214b600 id 69
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:191 remove mbuf 0x214f770 len 0
[Sat Apr 26 21:16:49 2014] nc_mbuf.c:121 put mbuf 0x214f770 len 0
[Sat Apr 26 21:16:49 2014] nc_response.c:284 c 8 is done
[Sat Apr 26 21:16:49 2014] nc_core.c:201 close c 8 '127.0.0.1:58469' on event FFFF eof 1 done 1 rb 10 sb 26
[Sat Apr 26 21:16:49 2014] nc_stats.c:1012 metric 'client_connections' in pool 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1044 decr field 'client_connections' to -1
[Sat Apr 26 21:16:49 2014] nc_stats.c:1012 metric 'client_eof' in pool 0
[Sat Apr 26 21:16:49 2014] nc_stats.c:1029 incr field 'client_eof' to 2
[Sat Apr 26 21:16:49 2014] nc_client.c:65 unref conn 0x214b4a0 owner 0x21422a0 from pool 'hoge'
[Sat Apr 26 21:16:49 2014] nc_connection.c:284 put conn 0x214b4a0
[Sat Apr 26 21:16:49 2014] nc_stats.c:969 skip swap of current 0x2147230 shadow 0x2146e00 as aggregator is busy
