Details
-
Bug
-
Resolution: Won't Do
-
Major
-
6.0.0
-
Untriaged
-
Unknown
Description
Following service exit observed in component level system test against 6.0.0-1501:
Service 'cbas' exited with status 137. Restarting. Messages:
2018-08-15T15:23:14.649-07:00 INFO CBAS.impls.AbstractLSMIndex [Executor-3685:96a80386e66b429ee1d780ebc5e7f2eb] Flushing component with id: [1534370522073,1534370522073] in the index {"class" : "LSMBTree", "dir" : "/data/idx/@analytics/v_iodevice_5/storage/partition_125/Default/ds1/3/idx_result1", "memory" : [
,
{"class":"LSMBTreeMemoryComponent", "state":"READABLE_UNWRITABLE_FLUSHING", "writers":0, "readers":1, "pendingFlushes":0, "id":"[1534370522073,1534370522073]"}], "disk" : 0, "num-scheduled-flushes":1, "current-memory-component":0}
2018-08-15T15:23:14.649-07:00 INFO CBAS.impls.AbstractLSMIndex [Executor-3688:96a80386e66b429ee1d780ebc5e7f2eb] Flushing component with id: [1534370522073,1534370522073] in the index {"class" : "LSMBTree", "dir" : "/data/idx/@analytics/v_iodevice_5/storage/partition_125/Default/ds1/3/ds1", "memory" : [
,
{"class":"LSMBTreeMemoryComponent", "state":"READABLE_UNWRITABLE_FLUSHING", "writers":0, "readers":2, "pendingFlushes":0, "id":"[1534370522073,1534370522073]"}], "disk" : 1, "num-scheduled-flushes":1, "current-memory-component":0}
[goport(/opt/couchbase/bin/cbas)] 2018/08/15 15:23:15 Timeout while flushing stderr
[goport(/opt/couchbase/bin/cbas)] 2018/08/15 15:23:15 child process exited with status 137
OOM killer not invoked in the .23 node - around the same timestamp from info log of the node:
2018-08-14T05:56:04.208-07:00 INFO CBAS.server.QueryServiceServlet [HttpExecutor(port:8095)-1] Cancelling query due to RuntimeDataException
|
2018-08-14T05:56:04.213-07:00 INFO CBAS.work.AbortTasksWork [Worker:956b344c972618e6d94bb93a5bbd7cdb] Aborting Tasks: JID:0.16502:[TAID:TID:ANID:ODID:2:0:2:0, TAID:TID:ANID:ODID:2:0:3:0, TAID:TID:ANID:ODID:2:0:4:0, TAID:TID:ANID:ODID:2:0:5:0, TAID:TID:ANID:ODID:2:0:6:0, TAID:TID:ANID:ODID:2:0:7:0, TAID:TID:ANID:ODID:2:0:8:0, TAID:TID:ANID:ODID:2:0:9:0]
|
2018-08-14T05:56:04.213-07:00 INFO CBAS.work.CleanupJobletWork [Worker:956b344c972618e6d94bb93a5bbd7cdb] Cleaning up after job: JID:0.16502
|
2018-08-14T05:56:04.214-07:00 INFO CBAS.messaging.NCMessageBroker [Worker:956b344c972618e6d94bb93a5bbd7cdb] Received message: org.apache.asterix.app.message.CancelQueryResponse@206a7f36
|
2018-08-14T05:56:04.217-07:00 INFO CBAS.server.QueryServiceServlet [HttpExecutor(port:8095)-1] handleException: request execution timed out: {"host":"172.23.104.23:8095","path":"/query/service","statement":"select sum(friends.num_friends) from (select array_length(profile.friends) as num_friends from ds3) as friends;","pretty":true,"mode":null,"clientContextID":"query_thread_16527","format":null,"timeout":"300s","maxResultReads":null,"planFormat":null,"expressionTree":false,"rewrittenExpressionTree":false,"logicalPlan":false,"optimizedLogicalPlan":false,"job":false,"signature":true,"multiStatement":false}
|
2018-08-14T05:56:04.258-07:00 INFO CBAS.server.QueryServiceServlet [HttpExecutor(port:8095)-1] handleRequest: {"host":"172.23.104.23:8095","path":"/query/service","statement":"select sum(friends.num_friends) from (select array_length(profile.friends) as num_friends from ds3) as friends;","pretty":true,"mode":null,"clientContextID":"query_thread_16604","format":null,"timeout":"300s","maxResultReads":null,"planFormat":null,"expressionTree":false,"rewrittenExpressionTree":false,"logicalPlan":false,"optimizedLogicalPlan":false,"job":false,"signature":true,"multiStatement":true}
|
2018-08-14T05:56:04.899-07:00 INFO CBAS.server.QueryServiceServlet [HttpExecutor(port:8095)-11] Cancelling query due to RuntimeDataException
|
2018-08-14T05:56:04.906-07:00 INFO CBAS.work.AbortTasksWork [Worker:956b344c972618e6d94bb93a5bbd7cdb] Aborting Tasks: JID:0.16503:[TAID:TID:ANID:ODID:2:0:2:0, TAID:TID:ANID:ODID:2:0:3:0, TAID:TID:ANID:ODID:2:0:4:0, TAID:TID:ANID:ODID:2:0:5:0, TAID:TID:ANID:ODID:2:0:6:0, TAID:TID:ANID:ODID:2:0:7:0, TAID:TID:ANID:ODID:2:0:8:0, TAID:TID:ANID:ODID:2:0:9:0]
|
2018-08-14T05:56:04.907-07:00 INFO CBAS.work.CleanupJobletWork [Worker:956b344c972618e6d94bb93a5bbd7cdb] Cleaning up after job: JID:0.16503
|
2018-08-14T05:56:04.907-07:00 INFO CBAS.messaging.NCMessageBroker [Worker:956b344c972618e6d94bb93a5bbd7cdb] Received message: org.apache.asterix.app.message.CancelQueryResponse@592f4453
|
2018-08-14T05:56:04.909-07:00 INFO CBAS.server.QueryServiceServlet [HttpExecutor(port:8095)-11] handleException: request execution timed out: {"host":"172.23.104.23:8095","path":"/query/service","statement":"SELECT name as id, result as bucketName, `type` as `Type`, array_length(profile.friends) as num_friends FROM ds1 where duration between 3009 and 3010 and profile is not missing and array_length(profile.friends) > 5 limit 100;","pretty":true,"mode":null,"clientContextID":"query_thread_16534","format":null,"timeout":"300s","maxResultReads":null,"planFormat":null,"expressionTree":false,"rewrittenExpressionTree":false,"logicalPlan":false,"optimizedLogicalPlan":false,"job":false,"signature":true,"multiStatement":false}
|
2018-08-14T05:56:05.349-07:00 INFO CBAS.server.QueryServiceServlet [HttpExecutor(port:8095)-11] handleRequest: {"host":"172.23.104.23:8095","path":"/query/service","statement":"SELECT name as id, result as bucketName, `type` as `Type`, array_length(profile.friends) as num_friends FROM ds2 where duration between 3009 and 3010 and profile is not missing;","pretty":true,"mode":null,"clientContextID":"query_thread_16610","format":null,"timeout":"300s","maxResultReads":null,"planFormat":null,"expressionTree":false,"rewrittenExpressionTree":false,"logicalPlan":false,"optimizedLogicalPlan":false,"job":false,"signature":true,"multiStatement":true}
|
2018-08-14T05:56:05.424-07:00 INFO CBAS.work.AbortTasksWork [Worker:956b344c972618e6d94bb93a5bbd7cdb] Aborting Tasks: JID:0.16504:[TAID:TID:ANID:ODID:2:0:2:0, TAID:TID:ANID:ODID:2:0:3:0, TAID:TID:ANID:ODID:2:0:4:0, TAID:TID:ANID:ODID:2:0:5:0, TAID:TID:ANID:ODID:2:0:6:0, TAID:TID:ANID:ODID:2:0:7:0, TAID:TID:ANID:ODID:2:0:8:0, TAID:TID:ANID:ODID:2:0:9:0]
|
2018-08-14T05:56:05.424-07:00 INFO CBAS.work.CleanupJobletWork [Worker:956b344c972618e6d94bb93a5bbd7cdb] Cleaning up after job: JID:0.16504
|
2018-08-14T05:56:05.845-07:00 INFO CBAS.work.AbortTasksWork [Worker:956b344c972618e6d94bb93a5bbd7cdb] Aborting Tasks: JID:0.16505:[TAID:TID:ANID:ODID:5:0:2:0, TAID:TID:ANID:ODID:5:0:3:0, TAID:TID:ANID:ODID:5:0:4:0, TAID:TID:ANID:ODID:5:0:5:0, TAID:TID:ANID:ODID:5:0:6:0, TAID:TID:ANID:ODID:5:0:7:0, TAID:TID:ANID:ODID:5:0:8:0, TAID:TID:ANID:ODID:5:0:9:0]
|
2018-08-14T05:56:05.845-07:00 INFO CBAS.work.CleanupJobletWork [Worker:956b344c972618e6d94bb93a5bbd7cdb] Cleaning up after job: JID:0.16505
|
[goport(/opt/couchbase/bin/cbas)] 2018/08/14 05:56:07 Timeout while flushing stderr
|
[goport(/opt/couchbase/bin/cbas)] 2018/08/14 05:56:07 child process exited with status 137
|
2018-08-14T05:56:07.761-07:00 INFO CBAS.cbas ++++++++++++ starting cbas main ++++++++++++
|
2018-08-14T05:56:07.761-07:00 INFO CBAS.cbas uuid: 956b344c972618e6d94bb93a5bbd7cdb
|
2018-08-14T05:56:07.761-07:00 INFO CBAS.cbas A single io device was provided; auto-adjusting...
|
2018-08-14T05:56:07.762-07:00 INFO CBAS.cbas io devices were adjusted to a total of: 8
|