Len out of range panic for Go client library when querying new, empty set


#1

Hello,

I’m coming across a strange panic with the Aerospike Go client library: “panic: runtime error: makeslice: len out of range”. I say strange because it occurs when I try to run a query (no filters) on an empty set more than 3-4 times in a row. In the aerospike logs, I see a “Scan failed with error -4” (below).

I can paste in my code if it helps but for now, here is the panic followed by my aerospike logs.

0xc2080da210 chans:[0xca0f348000] errs:[0xca0f352000] commands:[0xc20803a1b8]}
panic: runtime error: makeslice: len out of range

goroutine 22 [running]:
runtime.panic(0x39c400, 0x62d480)
  /usr/local/go/src/pkg/runtime/panic.c:279 +0xf5
github.com/aerospike/aerospike-client-go.(*info).sendCommand(0xc20803a1e0, 0xc208040020, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/info.go:123 +0x474
github.com/aerospike/aerospike-client-go.newInfo(0xc208040020, 0x76dd20, 0x3, 0x3, 0xc208040020, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/info.go:88 +0x1bb
github.com/aerospike/aerospike-client-go.RequestInfo(0xc208040020, 0x76dd20, 0x3, 0x3, 0x0, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/info.go:96 +0x5f
github.com/aerospike/aerospike-client-go.(*Node).Refresh(0xc2080480a0, 0x0, 0x0, 0x0, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/node.go:85 +0x166
github.com/aerospike/aerospike-client-go.(*Cluster).tend(0xc208046200, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/cluster.go:167 +0x1af
github.com/aerospike/aerospike-client-go.(*Cluster).clusterBoss(0xc208046200)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/cluster.go:110 +0x1ca
created by github.com/aerospike/aerospike-client-go.NewCluster
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/cluster.go:91 +0x2f0

goroutine 16 [IO wait]:
net.runtime_pollWait(0x715808, 0x72, 0x0)
  /usr/local/go/src/pkg/runtime/netpoll.goc:146 +0x66
net.(*pollDesc).Wait(0xc208045f70, 0x72, 0x0, 0x0)
  /usr/local/go/src/pkg/net/fd_poll_runtime.go:84 +0x46
net.(*pollDesc).WaitRead(0xc208045f70, 0x0, 0x0)
  /usr/local/go/src/pkg/net/fd_poll_runtime.go:89 +0x42
net.(*netFD).accept(0xc208045f10, 0x4b7380, 0x0, 0x714290, 0x23)
  /usr/local/go/src/pkg/net/fd_unix.go:419 +0x343
net.(*TCPListener).AcceptTCP(0xc20803a130, 0x76703, 0x0, 0x0)
  /usr/local/go/src/pkg/net/tcpsock_posix.go:234 +0x5d
net/http.tcpKeepAliveListener.Accept(0xc20803a130, 0x0, 0x0, 0x0, 0x0)
  /usr/local/go/src/pkg/net/http/server.go:1947 +0x4b
net/http.(*Server).Serve(0xc2080049c0, 0x715cb8, 0xc20803a130, 0x0, 0x0)
  /usr/local/go/src/pkg/net/http/server.go:1698 +0x91
net/http.(*Server).ListenAndServe(0xc2080049c0, 0x0, 0x0)
  /usr/local/go/src/pkg/net/http/server.go:1688 +0x14d
net/http.ListenAndServe(0xc208061730, 0x5, 0x715c58, 0xc208025aa0, 0x0, 0x0)
  /usr/local/go/src/pkg/net/http/server.go:1778 +0x79
github.com/codegangsta/negroni.(*Negroni).Run(0xc208025aa0, 0xc208061730, 0x5)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:102 +0x1fe
main.main()
  /Users/seenickcode/Code/go/src/github.com/shindighq/myproject/main.go:34 +0x2a8

goroutine 19 [finalizer wait]:
runtime.park(0x14d00, 0x633050, 0x631b09)
  /usr/local/go/src/pkg/runtime/proc.c:1369 +0x89
runtime.parkunlock(0x633050, 0x631b09)
  /usr/local/go/src/pkg/runtime/proc.c:1385 +0x3b
runfinq()
  /usr/local/go/src/pkg/runtime/mgc0.c:2644 +0xcf
runtime.goexit()
  /usr/local/go/src/pkg/runtime/proc.c:1445

goroutine 17 [syscall]:
runtime.goexit()
  /usr/local/go/src/pkg/runtime/proc.c:1445

goroutine 23 [select]:
github.com/shindighq/myproject/core.productsFromRecordSet(0xc2080054a0, 0x633b38, 0x0, 0x0, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/shindighq/myproject/core/product.go:188 +0x6b7
github.com/shindighq/myproject/core.(*myprojectCore).ListAllProducts(0xc208040500, 0x0, 0x0, 0x0, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/shindighq/myproject/core/product.go:159 +0x26a
github.com/shindighq/myproject/api.(*myprojectApi).listProducts(0xc20803a0b0, 0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/shindighq/myproject/api/product.go:19 +0xd2
github.com/shindighq/myproject/api.*myprojectApi.(github.com/shindighq/myproject/api.listProducts)·fm(0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/shindighq/myproject/api/routes.go:9 +0x44
net/http.HandlerFunc.ServeHTTP(0xc208060e40, 0x715e80, 0xc20800f540, 0xc208000c30)
  /usr/local/go/src/pkg/net/http/server.go:1235 +0x40
github.com/gorilla/mux.(*Router).ServeHTTP(0xc20801a780, 0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/gorilla/mux/mux.go:98 +0x292
github.com/codegangsta/negroni.func·001(0x715e80, 0xc20800f540, 0xc208000c30, 0xc208041b00)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:41 +0x56
github.com/codegangsta/negroni.HandlerFunc.ServeHTTP(0xc208061710, 0x715e80, 0xc20800f540, 0xc208000c30, 0xc208041b00)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:24 +0x4a
github.com/codegangsta/negroni.middleware.ServeHTTP(0x715c08, 0xc208061710, 0xc208041200, 0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:33 +0x8c
github.com/codegangsta/negroni.middleware.ServeHTTP·fm(0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:33 +0x56
github.com/codegangsta/negroni.(*Static).ServeHTTP(0xc208025a40, 0x715e80, 0xc20800f540, 0xc208000c30, 0xc208041ae0)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/static.go:49 +0x2eb
github.com/codegangsta/negroni.middleware.ServeHTTP(0x715be0, 0xc208025a40, 0xc2080411e0, 0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:33 +0x8c
github.com/codegangsta/negroni.middleware.ServeHTTP·fm(0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:33 +0x56
github.com/codegangsta/negroni.(*Logger).ServeHTTP(0xc20803a128, 0x715e80, 0xc20800f540, 0xc208000c30, 0xc208041aa0)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/logger.go:25 +0x18c
github.com/codegangsta/negroni.middleware.ServeHTTP(0x715bb8, 0xc20803a128, 0xc2080411c0, 0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:33 +0x8c
github.com/codegangsta/negroni.middleware.ServeHTTP·fm(0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:33 +0x56
github.com/codegangsta/negroni.(*Recovery).ServeHTTP(0xc208041100, 0x715e80, 0xc20800f540, 0xc208000c30, 0xc208041a80)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/recovery.go:45 +0x89
github.com/codegangsta/negroni.middleware.ServeHTTP(0x715b90, 0xc208041100, 0xc2080411a0, 0x715e80, 0xc20800f540, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:33 +0x8c
github.com/codegangsta/negroni.(*Negroni).ServeHTTP(0xc208025aa0, 0x715de8, 0xc208048be0, 0xc208000c30)
  /Users/seenickcode/Code/go/src/github.com/codegangsta/negroni/negroni.go:73 +0x10a
net/http.serverHandler.ServeHTTP(0xc2080049c0, 0x715de8, 0xc208048be0, 0xc208000c30)
  /usr/local/go/src/pkg/net/http/server.go:1673 +0x19f
net/http.(*conn).serve(0xc208046700)
  /usr/local/go/src/pkg/net/http/server.go:1174 +0xa7e
created by net/http.(*Server).Serve
  /usr/local/go/src/pkg/net/http/server.go:1721 +0x313

goroutine 41 [IO wait]:
net.runtime_pollWait(0x7156a8, 0x72, 0x0)
  /usr/local/go/src/pkg/runtime/netpoll.goc:146 +0x66
net.(*pollDesc).Wait(0xc208045020, 0x72, 0x0, 0x0)
  /usr/local/go/src/pkg/net/fd_poll_runtime.go:84 +0x46
net.(*pollDesc).WaitRead(0xc208045020, 0x0, 0x0)
  /usr/local/go/src/pkg/net/fd_poll_runtime.go:89 +0x42
net.(*netFD).Read(0xc208044fc0, 0xc2080de000, 0x8, 0x4000, 0x0, 0x714290, 0x23)
  /usr/local/go/src/pkg/net/fd_unix.go:242 +0x34c
net.(*conn).Read(0xc20803a148, 0xc2080de000, 0x8, 0x4000, 0x0, 0x0, 0x0)
  /usr/local/go/src/pkg/net/net.go:122 +0xe7
github.com/aerospike/aerospike-client-go.(*Connection).Read(0xc2080413c0, 0xc2080de000, 0x4000, 0x4000, 0x8, 0x0, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/connection.go:87 +0xd0
github.com/aerospike/aerospike-client-go.(*baseMultiCommand).readBytes(0xc208041ca0, 0x8, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/batch_command.go:129 +0x20d
github.com/aerospike/aerospike-client-go.(*baseMultiCommand).parseResult(0xc208041ca0, 0x716258, 0xc20803a1b8, 0xc2080413c0, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/batch_command.go:63 +0x57
github.com/aerospike/aerospike-client-go.(*queryCommand).parseResult(0xc208041cc0, 0x716258, 0xc20803a1b8, 0xc2080413c0, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/query_command.go:206 +0xa6
github.com/aerospike/aerospike-client-go.(*baseCommand).execute(0xc2080d73e0, 0x716258, 0xc20803a1b8, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/command.go:836 +0x6ca
github.com/aerospike/aerospike-client-go.(*queryRecordCommand).Execute(0xc20803a1b8, 0x0, 0x0)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/query_record_command.go:135 +0x75
created by github.com/aerospike/aerospike-client-go.(*Client).Query
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/client.go:1006 +0x4fb

goroutine 43 [chan receive]:
github.com/aerospike/aerospike-client-go.func·007(0xca0f352000)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/client.go:1247 +0x68
created by github.com/aerospike/aerospike-client-go.(*Client).mergeResultChannels
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/client.go:1261 +0x215

goroutine 42 [chan receive]:
github.com/aerospike/aerospike-client-go.func·006(0xca0f348000)
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/client.go:1240 +0x5f
created by github.com/aerospike/aerospike-client-go.(*Client).mergeResultChannels
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/client.go:1257 +0x19e

goroutine 44 [semacquire]:
sync.runtime_Semacquire(0xc2080da2a8)
  /usr/local/go/src/pkg/runtime/sema.goc:199 +0x30
sync.(*WaitGroup).Wait(0xc208041ce0)
  /usr/local/go/src/pkg/sync/waitgroup.go:129 +0x14b
github.com/aerospike/aerospike-client-go.func·008()
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/client.go:1267 +0x38
created by github.com/aerospike/aerospike-client-go.(*Client).mergeResultChannels
  /Users/seenickcode/Code/go/src/github.com/aerospike/aerospike-client-go/client.go:1270 +0x26f

Aerospike.log:

Jun 08 2015 15:49:20 GMT: INFO (scan): (thr_tscan.c::871) scan job received
Jun 08 2015 15:49:20 GMT: INFO (scan): (thr_tscan.c::901) scanning non-existent set stuffs
Jun 08 2015 15:49:20 GMT: INFO (tsvc): (thr_tsvc.c::451) Scan failed with error -4
Jun 08 2015 15:49:22 GMT: INFO (nsup): (thr_nsup.c::1319) {test} nsup start
Jun 08 2015 15:49:22 GMT: INFO (nsup): (thr_nsup.c::1237) {test} Records: 2, 0 0-vt, 0(0) expired, 0(0) evicted, 0(0) set deletes, 0(0) set evicted. Evict ttls: 0,0,0.000. Waits: 0,0,0. Total time: 5 ms
Jun 08 2015 15:49:22 GMT: INFO (nsup): (thr_nsup.c::1319) {default} nsup start
Jun 08 2015 15:49:22 GMT: INFO (nsup): (thr_nsup.c::1237) {default} Records: 18, 18 0-vt, 0(0) expired, 0(0) evicted, 0(0) set deletes, 0(0) set evicted. Evict ttls: 0,0,0.000. Waits: 0,0,0. Total time: 5 ms
Jun 08 2015 15:49:22 GMT: INFO (nsup): (thr_nsup.c::1319) {bar} nsup start
Jun 08 2015 15:49:22 GMT: INFO (nsup): (thr_nsup.c::1237) {bar} Records: 0, 0 0-vt, 0(0) expired, 0(0) evicted, 0(0) set deletes, 0(0) set evicted. Evict ttls: 0,0,0.000. Waits: 0,0,0. Total time: 6 ms
Jun 08 2015 15:49:25 GMT: INFO (drv_ssd): (drv_ssd.c::2536) device /opt/aerospike/data/default.dat: used 6912, contig-free 2097150M (2097150 wblocks), swb-free 0, n-w 0, w-q 0 w-tot 0 (0.0/s), defrag-q 0 defrag-tot 1 (0.0/s)
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4796)  system memory: free 237168kb ( 47 percent free ) 
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4804)  migrates in progress ( 0 , 0 ) ::: ClusterSize 1 ::: objects 20 ::: sub_objects 0
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4812)  rec refs 20 ::: rec locks 0 ::: trees 0 ::: wr reqs 0 ::: mig tx 0 ::: mig rx 0
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4818)  replica errs :: null 0 non-null 0 ::: sync copy errs :: node 0 :: master 0 
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4828)    trans_in_progress: wr 0 prox 0 wait 0 ::: q 0 ::: bq 0 ::: iq 0 ::: dq 0 : fds - proto (3, 174, 171) : hb (0, 0, 0) : fab (16, 16, 0)
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4830)    heartbeat_received: self 0 : foreign 0
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4831)    heartbeat_stats: bt 0 bf 0 nt 0 ni 0 nn 0 nnir 0 nal 0 sf1 0 sf2 0 sf3 0 sf4 0 sf5 0 sf6 0 mrf 0 eh 0 efd 0 efa 0 um 0 mcf 0 rc 0 
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4844)    tree_counts: nsup 0 scan 0 batch 0 dup 0 wprocess 0 migrx 0 migtx 0 ssdr 0 ssdw 0 rw 0
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4860) namespace test: disk inuse: 0 memory inuse: 272 (bytes) sindex memory inuse: 74558 (bytes) avail pct 100
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4860) namespace default: disk inuse: 6912 memory inuse: 3618 (bytes) sindex memory inuse: 75449 (bytes) avail pct 99
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4860) namespace bar: disk inuse: 0 memory inuse: 0 (bytes) sindex memory inuse: 0 (bytes) avail pct 100
Jun 08 2015 15:49:26 GMT: INFO (info): (thr_info.c::4905)    partitions: actual 12288 sync 0 desync 0 zombie 0 wait 0 absent 0
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::137) histogram dump: reads (277 total) msec
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::163)  (00: 0000000251) (02: 0000000025) (03: 0000000001)
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::137) histogram dump: writes_master (98 total) msec
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::163)  (00: 0000000096) (04: 0000000002)
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::137) histogram dump: proxy (0 total) msec
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::137) histogram dump: writes_reply (149 total) msec
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::163)  (00: 0000000147) (04: 0000000002)
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::137) histogram dump: udf (0 total) msec
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::137) histogram dump: query (122 total) msec
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::163)  (03: 0000000119) (04: 0000000002) (05: 0000000001)
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::137) histogram dump: query_rec_count (122 total) count
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::154)  (00: 0000000023) (01: 0000000069) (02: 0000000001) (04: 0000000019)
Jun 08 2015 15:49:26 GMT: INFO (info): (hist.c::163)  (05: 0000000010)
Jun 08 2015 15:49:29 GMT: INFO (scan): (thr_tscan.c::871) scan job received
Jun 08 2015 15:49:29 GMT: INFO (scan): (thr_tscan.c::901) scanning non-existent set stuffs
Jun 08 2015 15:49:29 GMT: INFO (tsvc): (thr_tsvc.c::451) Scan failed with error -4
Jun 08 2015 15:49:30 GMT: INFO (scan): (thr_tscan.c::871) scan job received
Jun 08 2015 15:49:30 GMT: INFO (scan): (thr_tscan.c::901) scanning non-existent set stuffs
Jun 08 2015 15:49:30 GMT: INFO (tsvc): (thr_tsvc.c::451) Scan failed with error -4
Jun 08 2015 15:49:30 GMT: INFO (scan): (thr_tscan.c::871) scan job received
Jun 08 2015 15:49:30 GMT: INFO (scan): (thr_tscan.c::901) scanning non-existent set stuffs
Jun 08 2015 15:49:30 GMT: INFO (tsvc): (thr_tsvc.c::451) Scan failed with error -4
Jun 08 2015 15:49:31 GMT: INFO (scan): (thr_tscan.c::871) scan job received
Jun 08 2015 15:49:31 GMT: INFO (scan): (thr_tscan.c::901) scanning non-existent set stuffs
Jun 08 2015 15:49:31 GMT: INFO (tsvc): (thr_tsvc.c::451) Scan failed with error -4
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4796)  system memory: free 237180kb ( 47 percent free ) 
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4804)  migrates in progress ( 0 , 0 ) ::: ClusterSize 1 ::: objects 20 ::: sub_objects 0
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4812)  rec refs 20 ::: rec locks 0 ::: trees 0 ::: wr reqs 0 ::: mig tx 0 ::: mig rx 0
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4818)  replica errs :: null 0 non-null 0 ::: sync copy errs :: node 0 :: master 0 
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4828)    trans_in_progress: wr 0 prox 0 wait 0 ::: q 0 ::: bq 0 ::: iq 0 ::: dq 0 : fds - proto (2, 175, 173) : hb (0, 0, 0) : fab (16, 16, 0)
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4830)    heartbeat_received: self 0 : foreign 0
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4831)    heartbeat_stats: bt 0 bf 0 nt 0 ni 0 nn 0 nnir 0 nal 0 sf1 0 sf2 0 sf3 0 sf4 0 sf5 0 sf6 0 mrf 0 eh 0 efd 0 efa 0 um 0 mcf 0 rc 0 
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4844)    tree_counts: nsup 0 scan 0 batch 0 dup 0 wprocess 0 migrx 0 migtx 0 ssdr 0 ssdw 0 rw 0
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4860) namespace test: disk inuse: 0 memory inuse: 272 (bytes) sindex memory inuse: 74558 (bytes) avail pct 100
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4860) namespace default: disk inuse: 6912 memory inuse: 3618 (bytes) sindex memory inuse: 75449 (bytes) avail pct 99
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4860) namespace bar: disk inuse: 0 memory inuse: 0 (bytes) sindex memory inuse: 0 (bytes) avail pct 100
Jun 08 2015 15:49:36 GMT: INFO (info): (thr_info.c::4905)    partitions: actual 12288 sync 0 desync 0 zombie 0 wait 0 absent 0
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::137) histogram dump: reads (277 total) msec
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::163)  (00: 0000000251) (02: 0000000025) (03: 0000000001)
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::137) histogram dump: writes_master (98 total) msec
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::163)  (00: 0000000096) (04: 0000000002)
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::137) histogram dump: proxy (0 total) msec
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::137) histogram dump: writes_reply (149 total) msec
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::163)  (00: 0000000147) (04: 0000000002)
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::137) histogram dump: udf (0 total) msec
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::137) histogram dump: query (122 total) msec
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::163)  (03: 0000000119) (04: 0000000002) (05: 0000000001)
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::137) histogram dump: query_rec_count (122 total) count
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::154)  (00: 0000000023) (01: 0000000069) (02: 0000000001) (04: 0000000019)
Jun 08 2015 15:49:36 GMT: INFO (info): (hist.c::163)  (05: 0000000010)
Jun 08 2015 15:49:45 GMT: INFO (drv_ssd): (drv_ssd.c::2536) device /opt/aerospike/data/default.dat: used 6912, contig-free 2097150M (2097150 wblocks), swb-free 0, n-w 0, w-q 0 w-tot 0 (0.0/s), defrag-q 0 defrag-tot 1 (0.0/s)
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4796)  system memory: free 237736kb ( 47 percent free ) 
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4804)  migrates in progress ( 0 , 0 ) ::: ClusterSize 1 ::: objects 20 ::: sub_objects 0
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4812)  rec refs 20 ::: rec locks 0 ::: trees 0 ::: wr reqs 0 ::: mig tx 0 ::: mig rx 0
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4818)  replica errs :: null 0 non-null 0 ::: sync copy errs :: node 0 :: master 0 
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4828)    trans_in_progress: wr 0 prox 0 wait 0 ::: q 0 ::: bq 0 ::: iq 0 ::: dq 0 : fds - proto (2, 175, 173) : hb (0, 0, 0) : fab (16, 16, 0)
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4830)    heartbeat_received: self 0 : foreign 0
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4831)    heartbeat_stats: bt 0 bf 0 nt 0 ni 0 nn 0 nnir 0 nal 0 sf1 0 sf2 0 sf3 0 sf4 0 sf5 0 sf6 0 mrf 0 eh 0 efd 0 efa 0 um 0 mcf 0 rc 0 
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4844)    tree_counts: nsup 0 scan 0 batch 0 dup 0 wprocess 0 migrx 0 migtx 0 ssdr 0 ssdw 0 rw 0
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4860) namespace test: disk inuse: 0 memory inuse: 272 (bytes) sindex memory inuse: 74558 (bytes) avail pct 100
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4860) namespace default: disk inuse: 6912 memory inuse: 3618 (bytes) sindex memory inuse: 75449 (bytes) avail pct 99
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4860) namespace bar: disk inuse: 0 memory inuse: 0 (bytes) sindex memory inuse: 0 (bytes) avail pct 100
Jun 08 2015 15:49:46 GMT: INFO (info): (thr_info.c::4905)    partitions: actual 12288 sync 0 desync 0 zombie 0 wait 0 absent 0
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::137) histogram dump: reads (277 total) msec
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::163)  (00: 0000000251) (02: 0000000025) (03: 0000000001)
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::137) histogram dump: writes_master (98 total) msec
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::163)  (00: 0000000096) (04: 0000000002)
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::137) histogram dump: proxy (0 total) msec
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::137) histogram dump: writes_reply (149 total) msec
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::163)  (00: 0000000147) (04: 0000000002)
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::137) histogram dump: udf (0 total) msec
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::137) histogram dump: query (122 total) msec
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::163)  (03: 0000000119) (04: 0000000002) (05: 0000000001)
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::137) histogram dump: query_rec_count (122 total) count
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::154)  (00: 0000000023) (01: 0000000069) (02: 0000000001) (04: 0000000019)
Jun 08 2015 15:49:46 GMT: INFO (info): (hist.c::163)  (05: 0000000010)

#2

Confirmed. This is due to a server change. Fix is coming today.


#3

Please try the latest code in github:master ($ go get -u .) and let me know if the problem persists.


#4

Ok thank you.

I guess I’m one of the first to debug this library :wink:


#5

A lot of people are using it in production. This was a new regression introduced after the last release of Client+Server combo. :wink:

Thanks for reporting the bugs. We appreciate your feedback, and rest assured issues will be addressed in under 24h.