Aerospike server in docker container abnormal exit (Panic)

Operations Containers (Docker, etc.)
1

Hi Guys,

 I run application and it write some records in server.I found the server exit without leaving fault information or call stack but some warning logs like follows.

Jan 13 2015 06:34:43 GMT: WARNING (rw): (write.c:814) {Data_base} write_master: bin op(s) expected, none present :0x8ede1be056a676aa776643b31039098c94547ba1

Jan 13 2015 06:34:43 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present :0x4a6e21813750a125ad866081ba74f7ba4bb75c78

Jan 13 2015 06:34:43 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present :0x08c660368107800829ea7fce14ead03befd9d714

Any clues to fix the problem,thanks in advance!My server version is 3.9.1.1

Steve

2

Can you paste the last 30 lines from your log leading up to and including the exit? Also output of ‘grep -v INFO aerospike.log’? And a snippet of your namespace config

3

Hi,Albot

The follows are the last lines.I found no real exit information.

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:164) NODE-ID bb900c9c0fe8002 CLUSTER-SIZE 1

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:226) system-memory: free-kbytes 7633472 free-pct 94

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:240) in-progress: tsvc-q 0 info-q 0 nsup-delete-q 0 rw-hash 0 proxy-hash 0 rec-refs 89

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:262) fds: proto (5,5,0) heartbeat (0,0,0) fabric (16,16,0)

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:271) heartbeat-received: self 0 foreign 0

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:312) batch-index: batches (278,0,0)

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:137) histogram dump: batch-index (278 total) msec

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:163) (00: 0000000226) (01: 0000000049) (02: 0000000003)

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:328) {Data_Ns1} objects: all 2 master 2 prole 0

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:366) {Data_Ns1} migrations: complete

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:385) {Data_Ns1} memory-usage: total-bytes 259 index-bytes 128 sindex-bytes 0 data-bytes 131 used-pct 0.00

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:508) {Data_Ns1} client: tsvc (0,0) proxy (0,0,0) read (104,0,0,1) write (210,0,0) delete (0,0,0,0) udf (0,0,0) lang (0,0,0,0)

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:536) {Data_Ns1} batch-sub: tsvc (0,0) proxy (0,0,0) read (104,0,0,0)

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:137) histogram dump: {Data_Ns1}-read (105 total) msec

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:163) (00: 0000000105)

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:137) histogram dump: {Data_Ns1}-write (210 total) msec

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:163) (00: 0000000210)

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:328) {Data_Ns2} objects: all 85 master 85 prole 0

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:366) {Data_Ns2} migrations: complete

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:385) {Data_Ns2} memory-usage: total-bytes 16593 index-bytes 5440 sindex-bytes 0 data-bytes 11153 used-pct 0.00

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:508) {Data_Ns2} client: tsvc (0,0) proxy (0,0,0) read (11589,0,0,19) write (540,20,0) delete (0,0,0,0) udf (0,0,0) lang (0,0,0,0)

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:536) {Data_Ns2} batch-sub: tsvc (0,0) proxy (0,0,0) read (258,0,0,52139)

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:137) histogram dump: {Data_Ns2}-read (11608 total) msec

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:163) (00: 0000011608)

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:137) histogram dump: {Data_Ns2}-write (560 total) msec

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:163) (00: 0000000560)

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:328) {Data_Ns3} objects: all 2 master 2 prole 0

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:366) {Data_Ns3} migrations: complete

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:385) {Data_Ns3} memory-usage: total-bytes 234 index-bytes 128 sindex-bytes 0 data-bytes 106 used-pct 0.00

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:415) {Data_Ns3} device-usage: used-bytes 512 avail-pct 99

Jan 14 2015 03:36:20 GMT: INFO (info): (ticker.c:508) {Data_Ns3} client: tsvc (0,0) proxy (0,0,0) read (35,0,0,0) write (2,0,0) delete (0,0,0,0) udf (0,0,0) lang (0,0,0,0)

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:137) histogram dump: {Data_Ns3-read (35 total) msec

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:163) (00: 0000000035)

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:137) histogram dump: {Data_Ns3-write (2 total) msec

Jan 14 2015 03:36:20 GMT: INFO (info): (hist.c:163) (00: 0000000002)

namespace config :

namespace Data_Ns1 {
replication-factor 2
memory-size 1G
default-ttl 0 # 5 days, use 0 to never expire/evict.
storage-engine memory
}

namespace Data_Ns2{
replication-factor 2
memory-size 1G
default-ttl 0 # 5 days, use 0 to never expire/evict.
storage-engine memory
}

namespace Data_Ns3 {
replication-factor 3
memory-size 1G
default-ttl 0 # 5 days, use 0 to never expire/evict.
storage-engine device {
file /root/data/persistent.dat
filesize 4G
data-in-memory true
}

'grep -v INFO aerospike.log ’

d577fc6570ef194ae8a31ae06a49471901d5cc31ad0a9480c7518-json.log {“log”:“link eth0 state up\n”,“stream”:“stdout”,“time”:“2015-01-14T04:09:59.119616716Z”}

{“log”:“link eth0 state up in 0\n”,“stream”:“stdout”,“time”:“2015-01-14T04:09:59.121342283Z”}

{“log”:“Jan 14 2015 04:10:04 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x4a6e21813750a125ad866081ba74f7ba4bb75c78\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:04.290829152Z”}

{“log”:“Jan 14 2015 04:10:04 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x4a6e21813750a125ad866081ba74f7ba4bb75c78\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:04.294124545Z”}

{“log”:“Jan 14 2015 04:10:04 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x4a6e21813750a125ad866081ba74f7ba4bb75c78\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:04.297271888Z”} {“log”:“Jan 14 2015 04:10:04 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x4a6e21813750a125ad866081ba74f7ba4bb75c78\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:04.300413023Z”}

{“log”:“Jan 14 2015 04:10:04 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x4a6e21813750a125ad866081ba74f7ba4bb75c78\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:04.303626463Z”} {“log”:“Jan 14 2015 04:10:04 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x4a6e21813750a125ad866081ba74f7ba4bb75c78\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:04.304765634Z”}

{“log”:“Jan 14 2015 04:10:07 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:07.966711493Z”}

{“log”:“Jan 14 2015 04:10:07 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:07.970929703Z”} {“log”:“Jan 14 2015 04:10:07 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:07.975661341Z”}

{“log”:“Jan 14 2015 04:10:07 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:07.979479864Z”}

{“log”:“Jan 14 2015 04:10:07 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:07.980624489Z”}

{“log”:“Jan 14 2015 04:10:07 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:07.984931497Z”} {“log”:“Jan 14 2015 04:10:07 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:07.990196471Z”} {“log”:“Jan 14 2015 04:10:07 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:07.994952223Z”}

{“log”:“Jan 14 2015 04:10:08 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:08.290931062Z”}

{“log”:“Jan 14 2015 04:10:08 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:08.293250089Z”} {“log”:“Jan 14 2015 04:10:08 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:08.295783694Z”} {“log”:“Jan 14 2015 04:10:13 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:13.290203392Z”}

{“log”:“Jan 14 2015 04:10:18 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:18.29250309Z”}

{“log”:“Jan 14 2015 04:10:23 GMT: WARNING (rw): (write.c:814) {Data_Ns2} write_master: bin op(s) expected, none present \u003cDigest\u003e:0x8ede1be056a676aa776643b31039098c94547ba1\n”,“stream”:“stderr”,“time”:“2015-01-14T04:10:23.292461147Z”}

Best Regards,

Steve

4

I’ve never seen that. What kind of operations are you doing to generate these messages?

5

Hi,Albot

Finally got the the core-dump.there are segmentation faults.

Core was generated by `asd --foreground’. Program terminated with signal 11, Segmentation fault.

#0 0x000000000053ca0e in cf_fault_event2 (context=context@entry=AS_RW, severity=severity@entry=CF_WARNING, file_name=file_name@entry=0x7269e7 “write.c”, line=814, mem_ptr=0x7feb9378ea1c, len=20, dt=CF_DISPLAY_HEX_DIGEST, msg=0x726268 "{%s} write_master: bin op(s) expected, none present ") at fault.c:684 684 fault.c: No such file or directory. (zdb) where

#0 0x000000000053ca0e in cf_fault_event2 (context=context@entry=AS_RW, severity=severity@entry=CF_WARNING, file_name=file_name@entry=0x7269e7 “write.c”, line=814, mem_ptr=0x7feb9378ea1c, len=20, dt=CF_DISPLAY_HEX_DIGEST, msg=0x726268 "{%s} write_master: bin op(s) expected, none present ") at fault.c:684

#1 0x0000000000530257 in write_master_policies (tr=tr@entry=0x7feb9378ea00, p_must_not_create=p_must_not_create@entry=0x7feb92fb2f23, p_record_level_replace=p_record_level_replace@entry=0x7feb92fb2f24, p_must_fetch_data=p_must_fetch_data@entry=0x7feb92fb2f25, p_increment_generation=p_increment_generation@entry=0x7feb92fb2f26) at transaction/write.c:848 #2 0x0000000000533723 in write_master (rw=rw@entry=0x7fec9581a008, tr=tr@entry=0x7feb9378ea00) at transaction/write.c:503

#3 0x0000000000534274 in as_write_start (tr=0x7feb9378ea00) at transaction/write.c:227

#4 0x00000000004e00c5 in process_transaction (tr=tr@entry=0x7feb9378ea00) at base/thr_tsvc.c:334

#5 0x00000000004e047c in thr_tsvc_process_or_enqueue (tr=tr@entry=0x7feb9378ea00) at base/thr_tsvc.c:509

#6 0x00000000004bf374 in thr_demarshal (arg=) at base/thr_demarshal.c:846

#7 0x00007fed51f5d414 in start_thread () from /lib/libpthread.so.0

#8 0x00007fed50dde19f in clone () from /lib/libc.so.6

Best Regards.