Details
-
Bug
-
Resolution: Cannot Reproduce
-
Critical
-
Cheshire-Cat
-
7.0.0-4170
-
Untriaged
-
-
1
-
Unknown
Description
We are seeing memcached crashes on 4 separate nodes during our n1ql transactions system test for the node given here the crash is at 08:13:26. We see the same behavior on the other data nodes that crashed, will attach logs for all 4 as well as when they crashed. Also attaching logs of a query node 172.23.104.21
172.23.104.16 : 08:13:26
172.23.104.17: 08:11:44
172.23.104.18: 08:16:05
172.23.104.19: 08:15:17
In the test itself transactions began running at 06:28:46 and finished at 08:48:15. Later on in the system test we see similar behavior, where the memcached nodes crash during the transaction runs.
/opt/couchbase/var/lib/couchbase/logs/info.log:[user:info,2021-01-12T08:13:26.597-08:00,ns_1@172.23.104.16:<0.11086.0>:ns_log:crash_consumption_loop:69]Service 'memcached' exited with status 137. Restarting. Messages:
|
If we check this timestamp we see that the node is OOM:
[root@cnt7-qe1 ~]# dmesg -T | grep -i "out of memory"
|
[Tue Jan 12 08:13:20 2021] Out of memory: Kill process 64087 (memcached) score 790 or sacrifice child
|
[Tue Jan 12 08:13:20 2021] Out of memory: Kill process 64089 (memcached) score 790 or sacrifice child
|
|
If we check the memcached logs around this time we see this slow operation warning:
2021-01-12T08:13:00.667540-08:00 WARNING 340: Slow operation. {"cid":"172.23.97.83:46408/0","duration":"5129 ms","trace":"request=1038140068077781:5129845","command":"GET_ALL_VB_SEQNOS","peer":"{"ip":"172.23.97.83","port":46408}","bucket":"bucket3","packet":{"bodylen":4,"cas":0,"datatype":"raw","extlen":4,"key":"<ud></ud>","keylen":0,"magic":"ClientRequest","opaque":0,"opcode":"GET_ALL_VB_SEQNOS","vbucket":0}}
|
2021-01-12T08:13:00.667517-08:00 WARNING 231: Slow operation. {"cid":"172.23.96.30:35746/0","duration":"5533 ms","trace":"request=1038139640104401:5533234","command":"GET_ALL_VB_SEQNOS","peer":"{"ip":"172.23.96.30","port":35746}","bucket":"bucket3","packet":{"bodylen":4,"cas":0,"datatype":"raw","extlen":4,"key":"<ud></ud>","keylen":0,"magic":"ClientRequest","opaque":0,"opcode":"GET_ALL_VB_SEQNOS","vbucket":0}}
|
2021-01-12T08:13:00.695827-08:00 WARNING 221: Slow operation. {"cid":"c049e821a4a7ad18/0c97291ef3d93c8c/d12","duration":"1011 ms","trace":"request=1038148297012481:1011078","command":"GET_CLUSTER_CONFIG","peer":"{"ip":"172.23.104.23","port":34214}","bucket":"bucket4","packet":{"bodylen":0,"cas":0,"datatype":"raw","extlen":0,"key":"<ud></ud>","keylen":0,"magic":"ClientRequest","opaque":302841856,"opcode":"GET_CLUSTER_CONFIG","vbucket":0}}
|
2021-01-12T08:13:00.715680-08:00 WARNING 81: Slow operation. {"cid":"127.0.0.1:38518/0","duration":"12 s","trace":"request=1038137513143626:12175295","command":"STAT","peer":"{"ip":"127.0.0.1","port":38518}","bucket":"bucket2","packet":{"bodylen":8,"cas":0,"datatype":"raw","extlen":0,"key":"<ud>dcpagg.:</ud>","keylen":8,"magic":"ClientRequest","opaque":0,"opcode":"STAT","vbucket":0}}
|
2021-01-12T08:13:00.803597-08:00 INFO (bucket2) DCP (Producer) eq_dcpq:secidx:proj-bucket2-MAINT_STREAM_TOPIC_5769e97ec1395454814a6ff5e5bfb7e2-18405484233030147622/3 - Notifying paused connection now that DcpProducer::BufferLog is no longer full; ackedBytes:2959667395, bytesSent:18653581, maxBytes:20971520
|
2021-01-12T08:13:13.610630-08:00 WARNING 235: Slow operation. {"cid":"172.23.97.83:41558/0","duration":"3714 ms","trace":"request=1038155381409997:3714817","command":"GET_ALL_VB_SEQNOS","peer":"{"ip":"172.23.97.83","port":41558}","bucket":"bucket2","packet":{"bodylen":0,"cas":0,"datatype":"raw","extlen":0,"key":"<ud></ud>","keylen":0,"magic":"ClientRequest","opaque":0,"opcode":"GET_ALL_VB_SEQNOS","vbucket":0}}
|
2021-01-12T08:13:13.610157-08:00 WARNING 93: Slow operation. {"cid":"127.0.0.1:46420/0","duration":"9263 ms","trace":"request=1038149817263470:9263155","command":"STAT","peer":"{"ip":"127.0.0.1","port":46420}","bucket":"bucket3","packet":{"bodylen":7,"cas":0,"datatype":"raw","extlen":0,"key":"<ud>topkeys</ud>","keylen":7,"magic":"ClientRequest","opaque":0,"opcode":"STAT","vbucket":0}}
|