[System Test] : Plasma panic - plasmaSlice::handleCommandsWorker: panic detected while processing mutation for operation 1 key

2020-07-13T09:22:18.766-07:00 [Fatal] plasmaSlice::handleCommandsWorker: panic detected while processing mutation for operation 1 key = <ud>(^H^E>>357474-^@^FSUCCESS^@^@^FEC871234A50CF132F1CF12F003EBC0DF0E0C353799D35826EE6C3891D19E107625835BA1FB81C220^@^@^@)</ud> docid = <ud>(FC7CAB77-131_207073)</ud> Index default_result_ratings_claims_pindex, Bucket default, IndexInstId 5271043880651076522, PartitionId 2

2020-07-13T09:22:18.766-07:00 [Info] default/default_result_ratings_claims_pindex/Backstore#5271043880651076522:2 Plasma:

"low:":         <ud>(FC7CAB77-131_206555, sn:1, insert:false)</ud>,

"high:":        <ud>(FC7CAB77-131_206555, sn:1, insert:false)</ud>,

"chainLen:":    3,

"numItems:":    153,

"state:":       8001,

"flushed:":     true,

"full:":        true,

"evicted:":     false

 0 split: op 5 itm=[item key:<ud>(FC7CAB77-131_206555)</ud> val:<ud>((nil))</ud> sn:1 insert: false]

 1 insert/delete: op 3 itm=[item key:<ud>(FC7CAB77-131_207087)</ud> val:<ud>(^H^E>>357474-^@^FSUCCESS^@^@^FEC871234A50CF132F1CF12F003EBC0DF0E0C353799D35826EE6C3891D19E107625835BA1FB81C220^@^@^@^@^@)</ud> sn:579368 insert: true]

 2 delta: op 9

 3 base:

...

...

115:  <ud>(FC7CAB77-131_206746, sn:579259, insert:true)</ud>

          116:  <ud>(FC7CAB77-131_206747, sn:579259, insert:true)</ud>

          117:  <ud>(FC7CAB77-131_206748, sn:579259, insert:true)</ud>

          118:  <ud>(FC7CAB77-131_206749, sn:579259, insert:true)</ud>

          119:  <ud>(FC7CAB77-131_206750, sn:579259, insert:true)</ud>

          120:  <ud>(FC7CAB77-131_207, sn:527227, insert:false)</ud>

          121:  <ud>(FC7CAB77-131_206523, sn:579214, insert:true)</ud>

          122:  <ud>(FC7CAB77-131_206524, sn:579214, insert:true)</ud>

          123:  <ud>(FC7CAB77-131_206525, sn:579212, insert:true)</ud>

          124:  <ud>(FC7CAB77-131_206526, sn:579214, insert:true)</ud>

          125:  <ud>(FC7CAB77-131_206527, sn:579213, insert:true)</ud>

          126:  <ud>(FC7CAB77-131_206528, sn:579214, insert:true)</ud>

          127:  <ud>(FC7CAB77-131_206529, sn:579214, insert:true)</ud>

          128:  <ud>(FC7CAB77-131_206530, sn:579214, insert:true)</ud>

...

...

2020-07-13T09:22:18.771-07:00 [Fatal] goroutine 544 [running]:

github.com/couchbase/indexing/secondary/logging.(*destination).StackTraceAll(0x1b28d60, 0x7, 0x7)

        goproj/src/github.com/couchbase/indexing/secondary/logging/logging.go:175 +0x74

github.com/couchbase/indexing/secondary/logging.StackTraceAll(0x116eb74, 0xa4)

        goproj/src/github.com/couchbase/indexing/secondary/logging/logging.go:317 +0x2d

github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).handleCommandsWorker.func1(0xc43737bd78, 0xc427db0a00)

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:527 +0x2ff

panic(0xf7e700, 0xc428d13de0)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.7.6/go/src/runtime/panic.go:458 +0x243

github.com/couchbase/plasma.(*Plasma).fatalPanic(0xc427db0f00, 0xc434726c80, 0x124)

        goproj/src/github.com/couchbase/plasma/plasma.go:2133 +0x2f5

github.com/couchbase/plasma.(*Plasma).trySMOs2(0xc427db0f00, 0x7f6a0c787e70, 0x1ae8220, 0xc43e2ef940, 0xc420149180, 0xb4e401, 0x12c, 0x5, 0x1e, 0x4, ...)

        goproj/src/github.com/couchbase/plasma/plasma.go:1845 +0x5d7

github.com/couchbase/plasma.(*Plasma).trySMOs(0xc427db0f00, 0x7f6a0c787e70, 0x1ae8220, 0xc43e2ef940, 0xc420149180, 0xc43e2ef901, 0x0)

        goproj/src/github.com/couchbase/plasma/plasma.go:1797 +0x96

github.com/couchbase/plasma.(*Writer).Insert(0xc426dc5160, 0x7f6b34ef1400, 0x13, 0x20)

        goproj/src/github.com/couchbase/plasma/plasma.go:1979 +0xf5

github.com/couchbase/plasma.(*Writer).InsertKV(0xc426dc5160, 0xc442803160, 0x13, 0x20, 0xc426a44000, 0x6c, 0x3702, 0x0, 0x0)

        goproj/src/github.com/couchbase/plasma/mvcc.go:342 +0x142

github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).insertSecIndex(0xc427db0a00, 0xc424031b20, 0x6a, 0x70, 0xc442803160, 0x13, 0x20, 0x1, 0xc43737bc00, 0xc42b287200, ...)

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:731 +0x4fc

github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).insert(0xc427db0a00, 0xc424031b20, 0x6a, 0x70, 0xc442803160, 0x13, 0x20, 0x1, 0x0, 0xc42b287200, ...)

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:667 +0x168

github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).handleCommandsWorker(0xc427db0a00, 0x1)

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:541 +0x2b4

created by github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).initWriters

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:2708 +0x3d8

...

...

goroutine 23072679 [sleep]:

time.Sleep(0x5f5e100)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.7.6/go/src/runtime/time.go:59 +0xe1

github.com/couchbase/plasma.(*Plasma).monitorStatistics(0xc435997400)

        goproj/src/github.com/couchbase/plasma/plasma.go:987 +0x181

created by github.com/couchbase/plasma.New

        goproj/src/github.com/couchbase/plasma/plasma.go:718 +0x12bd

panic: default/default_result_ratings_claims_pindex/Backstore#5271043880651076522:2 : fatal: Incorrect page split detected - splitKey:item key:<ud>(FC7CAB77-131_206555)</ud> val:<ud>((nil))</ud> sn:1 insert: false pageRange:(item key:<ud>(FC7CAB77-131_206555)</ud> val:<ud>((nil))</ud> sn:1 insert: false,item key:<ud>(FC7CAB77-131_207118)</ud> val:<ud>((nil))</ud> sn:1 insert: false) [recovered]

        panic: default/default_result_ratings_claims_pindex/Backstore#5271043880651076522:2 : fatal: Incorrect page split detected - splitKey:item key:<ud>(FC7CAB77-131_206555)</ud> val:<ud>((nil))</ud> sn:1 insert: false pageRange:(item key:<ud>(FC7CAB77-131_206555)</ud> val:<ud>((nil))</ud> sn:1 insert: false,item key:<ud>(FC7CAB77-131_207118)</ud> val:<ud>((nil))</ud> sn:1 insert: false)

goroutine 544 [running]:

panic(0xf7e700, 0xc428d13de0)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.7.6/go/src/runtime/panic.go:500 +0x1a1

github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).handleCommandsWorker.func1(0xc43737bd78, 0xc427db0a00)

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:528 +0x3a8

panic(0xf7e700, 0xc428d13de0)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.7.6/go/src/runtime/panic.go:458 +0x243

github.com/couchbase/plasma.(*Plasma).fatalPanic(0xc427db0f00, 0xc434726c80, 0x124)

        goproj/src/github.com/couchbase/plasma/plasma.go:2133 +0x2f5

github.com/couchbase/plasma.(*Plasma).trySMOs2(0xc427db0f00, 0x7f6a0c787e70, 0x1ae8220, 0xc43e2ef940, 0xc420149180, 0xb4e401, 0x12c, 0x5, 0x1e, 0x4, ...)

        goproj/src/github.com/couchbase/plasma/plasma.go:1845 +0x5d7

github.com/couchbase/plasma.(*Plasma).trySMOs(0xc427db0f00, 0x7f6a0c787e70, 0x1ae8220, 0xc43e2ef940, 0xc420149180, 0xc43e2ef901, 0x0)

        goproj/src/github.com/couchbase/plasma/plasma.go:1797 +0x96

github.com/couchbase/plasma.(*Writer).Insert(0xc426dc5160, 0x7f6b34ef1400, 0x13, 0x20)

        goproj/src/github.com/couchbase/plasma/plasma.go:1979 +0xf5

github.com/couchbase/plasma.(*Writer).InsertKV(0xc426dc5160, 0xc442803160, 0x13, 0x20, 0xc426a44000, 0x6c, 0x3702, 0x0, 0x0)

        goproj/src/github.com/couchbase/plasma/mvcc.go:342 +0x142

github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).insertSecIndex(0xc427db0a00, 0xc424031b20, 0x6a, 0x70, 0xc442803160, 0x13, 0x20, 0x1, 0xc43737bc00, 0xc42b287200, ...)

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:731 +0x4fc

github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).insert(0xc427db0a00, 0xc424031b20, 0x6a, 0x70, 0xc442803160, 0x13, 0x20, 0x1, 0x0, 0xc42b287200, ...)

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:667 +0x168

github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).handleCommandsWorker(0xc427db0a00, 0x1)

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:541 +0x2b4

created by github.com/couchbase/indexing/secondary/indexer.(*plasmaSlice).initWriters

        goproj/src/github.com/couchbase/indexing/secondary/indexer/plasma_slice.go:2708 +0x3d8

2020-07-13T09:22:20.090-07:00 [Info] Indexer started with command line: [/opt/couchbase/bin/indexer -adminPort=9100 -scanPort=9101 -httpPort=9102 -streamInitPort=9103 -streamCatchupPort=9104 -streamMaintPort=9105 --httpsPort=19102 --certFile=/opt/couchbase/var/lib/couchbase/config/memcached-cert.pem --keyFile=/opt/couchbase/var/lib/couchbase/config/memcached-key.pem -vbuckets=1024 -cluster=127.0.0.1:8091 -storageDir=/data/@2i -diagDir=/opt/couchbase/var/lib/couchbase/crash -nodeUUID=a8cbcb3a31b360d70ec758bbb7a97ef2 -ipv6=false -isEnterprise=true]

2020-07-13T09:22:20.109-07:00 [Info] Indexer::NewIndexer Status Warmup

2020-07-13T09:22:20.114-07:00 [Info] Setting buffer block size to 16384 bytes

2020-07-13T09:22:20.114-07:00 [Info] Setting maxcpus = 8

2020-07-13T09:22:20.114-07:00 [Info] Setting log level to Info

2020-07-13T09:22:20.115-07:00 [Info] Recieve security change notification. code 3

2020-07-13T09:22:33.211-07:00 [Info] SCAN##123 RESPONSE status:(error = Index not ready for serving queries), requestId: 4db7f526-75df-4ccf-80d4-8d32773a064d

2020-07-13T09:22:33.306-07:00 [Info] SCAN##124 REQUEST defnId:6982981632355334399, instId:0, index:/, type:scan, partitions:[0], span:<ud>(range (%!s(<nil>),%!s(<nil>) incl:none))</ud>, limit:100, requestId:56e6d5ed-a44b-41c8-bddf-ef1f0118693a

2020-07-13T09:22:33.307-07:00 [Info] SCAN##124 RESPONSE status:(error = Index not ready for serving queries), requestId: 56e6d5ed-a44b-41c8-bddf-ef1f0118693a

2020-07-13T09:22:33.464-07:00 [Error] plasmaSlice:NewplasmaSlice Id 0x68b3a0 IndexInstId 5271043880651076522 fatal error occured: Unable to initialize /data/@2i/default_default_result_ratings_claims_pindex_5271043880651076522_2.index/docIndex, err = Fatal error: default/default_result_ratings_claims_pindex/Backstore#5271043880651076522:2 : fatal: Incorrect page split detected - splitKey:item key:<ud>(FC7CAB77-131_206555)</ud> val:<ud>((nil))</ud> sn:1 insert: false pageRange:(item key:<ud>(FC7CAB77-131_206555)</ud> val:<ud>((nil))</ud> sn:1 insert: false,item key:<ud>(FC7CAB77-131_207118)</ud> val:<ud>((nil))</ud> sn:1 insert: false)

2020-07-13T09:22:33.464-07:00 [Error] plasmaSlice:NewplasmaSlice Id 0 IndexInstId 5271043880651076522 PartitionId 2 fatal error occured: Storage corrupted and unrecoverable

2020-07-13T09:22:33.464-07:00 [Error] Indexer:: initPartnInstance storage corruption for indexInst

        InstId: 5271043880651076522

        Defn: DefnId: 7103571023542823578 Name: default_result_ratings_claims_pindex Using: plasma Bucket: default IsPrimary: false NumReplica: 1 InstVersion: 0

                SecExprs: <ud>([`rating` `result` `claim`])</ud>

                Desc: [false false false]

                PartitionScheme: KEY

                HashScheme: CRC32 PartitionKeys: [`rating`] WhereExpr: <ud>()</ud> RetainDeletedXATTR: false

        State: INDEX_STATE_ACTIVE

        RState: RebalActive

        Stream: MAINT_STREAM

        Version: 1

        ReplicaId: 1

        PartitionContainer: &{map[2:{2 1 [:9105]}] 1024 4 256 KEY 0} partnDefn {2 1 [:9105]}

2020-07-13T09:22:33.468-07:00 [Info] Indexer::initFromPersistedState Starting cleanup for PartitionId: 2 Endpoints: [:9105]

2020-07-13T09:22:33.468-07:00 [Info] Indexer::forceCleanupIndexPartition 5271043880651076522 2 mark metadata as deleted

2020-07-13T09:22:33.468-07:00 [Info] ClustMgr:handleCleanupPartition&{{7103571023542823578 default_result_ratings_claims_pindex plasma default 177dd51d8ddebd6ce877ce0dcf827ca1 false [`rating` `result` `claim`] N1QL KEY   [false false false] true true [] false 1 [`rating`] false 0 {true 1 0 0} 0 0 0 0 0 0 0 0 [] [] 0 0} 5271043880651076522 2 1 true}

2020-07-13T09:22:33.468-07:00 [Info] LifecycleMgr.DeleteOrPruneIndexInstance() : index defnId 7103571023542823578 instance id 5271043880651076522 real instance id 0 partitions [2]

2020-07-13T09:22:33.468-07:00 [Info] LifecycleMgr.PruneIndexPartition() : index defnId 7103571023542823578 instance 5271043880651076522 partitions [2]

2020-07-13T09:22:33.468-07:00 [Info] LifecycleMgr.DeleteIndexInstance() : index defnId 7103571023542823578 instance id 5271043880651076522

2020-07-13T09:22:33.475-07:00 [Info] lifecycleMgr.dispatchRequest: op OPCODE_CLEANUP_PARTITION elapsed 6.927762ms len(expediates) 0 len(incomings) 0 len(outgoings) 0

2020-07-13T09:22:33.475-07:00 [Info] Indexer::forceCleanupIndexPartition Cleaning up data files for 5271043880651076522 2