System Longevity Test : Panic in eventing logs when undeploying handlers

[2018-08-24T18:52:09-07:00, sequoiatools/eventing:e3dd48] /eventing.py 172.23.98.135 8096 bucket_op_function_integration.json Administrator password undeploy true

[2018-08-24T18:52:26-07:00, sequoiatools/eventing:1a5f18] /eventing.py 172.23.98.135 8096 bucket_op_complex_function_integration.json Administrator password undeploy true

2018-08-24T18:52:09.724-07:00 [Info] SuperSupervisor::SettingsChangeCallback [2] Path => /eventing/appsettings/bucket_op_function value => map[string]interface {}{"dcp_stream_boundary":"from_now", "deadline_timeout":62, "deployment_status":false, "execution_timeout":60, "log_level":"INFO", "processing_status":false}

2018-08-24T18:52:09.724-07:00 [Info] SuperSupervisor::SettingsChangeCallback [2] Function: bucket_op_function current state: 2 requested status for deployment: false processing: false

2018-08-24T18:52:09.724-07:00 [Info] SuperSupervisor::SettingsChangeCallback [2] Function: bucket_op_function Begin undeploy process. Current state: 2

2018-08-24T18:52:09.724-07:00 [Info] SuperSupervisor::SettingsChangeCallback [2] Function: bucket_op_function enabled, settings change requesting undeployment

2018-08-24T18:52:09.724-07:00 [Info] SuperSupervisor::deleteFromLocallyDeployedApps [2] Function: bucket_op_function deleting from locally deployed apps map

2018-08-24T18:52:09.724-07:00 [Info] SuperSupervisor::CleanupProducer [2] Function: bucket_op_function stopping running instance of Eventing.Producer

2018-08-24T18:52:10.878-07:00 [Info] Producer::SignalCheckpointBlobCleanup [bucket_op_function:3] Purged all owned checkpoint & debugger blobs from metadata bucket: NEW_ORDER

2018-08-24T18:52:10.878-07:00 [Info] Producer::StopRunningConsumers [bucket_op_function:3] Stopping running instances of Eventing.Consumer

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Gracefully shutting down consumer routine

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Gracefully shutting down consumer routine

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Gracefully shutting down consumer routine

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Issued close for go-couchbase and gocb handles

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Requested to remove supervision of eventing-consumer

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Stopped checkpoint, restart vb dcp stream and stats tickers

2018-08-24T18:52:10.878-07:00 [Info] Consumer::sendMessageLoop [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Exiting send message routine

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Issued close for go-couchbase and gocb handles

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Requested to remove supervision of eventing-consumer

2018-08-24T18:52:10.878-07:00 [Info] Consumer::Stop [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Stopped checkpoint, restart vb dcp stream and stats tickers

2018-08-24T18:52:10.878-07:00 [Info] Consumer::sendMessageLoop [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Exiting send message routine

2018-08-24T18:52:10.879-07:00 [Info] Consumer::Stop [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Issued close for go-couchbase and gocb handles

2018-08-24T18:52:10.879-07:00 [Info] Consumer::Stop [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Requested to remove supervision of eventing-consumer

2018-08-24T18:52:10.879-07:00 [Error] Consumer::Stop [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Consumer stop routine, recover runtime error: index out of range stack trace: goroutine 153932 [running]:

runtime/debug.Stack(0xc422160a40, 0xbeb780, 0x14cd380)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.10.3/go/src/runtime/debug/stack.go:24 +0xa7

github.com/couchbase/eventing/consumer.(*Consumer).Stop.func1(0xd056e8, 0xe, 0xc424aec000)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/consumer/v8_consumer.go:368 +0x6e

panic(0xbeb780, 0x14cd380)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.10.3/go/src/runtime/panic.go:502 +0x229

github.com/couchbase/eventing/consumer.(*Consumer).Stop(0xc424aec000)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/consumer/v8_consumer.go:442 +0x194c

github.com/couchbase/eventing/suptree.(*Supervisor).removeService.func1.1(0xdbd380, 0xc424aec000, 0xc424954000, 0xb3, 0xc42b2cbce0)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/suptree/supervisor.go:413 +0x31

created by github.com/couchbase/eventing/suptree.(*Supervisor).removeService.func1

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/suptree/supervisor.go:412 +0xa3

2018-08-24T18:52:10.879-07:00 [Error] Consumer::Stop [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Consumer stop routine, recover runtime error: index out of range stack trace: goroutine 154002 [running]:

runtime/debug.Stack(0xc420db8a40, 0xbeb780, 0x14cd380)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.10.3/go/src/runtime/debug/stack.go:24 +0xa7

github.com/couchbase/eventing/consumer.(*Consumer).Stop.func1(0xd056e8, 0xe, 0xc425ff8000)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/consumer/v8_consumer.go:368 +0x6e

panic(0xbeb780, 0x14cd380)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.10.3/go/src/runtime/panic.go:502 +0x229

github.com/couchbase/eventing/consumer.(*Consumer).Stop(0xc425ff8000)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/consumer/v8_consumer.go:442 +0x194c

github.com/couchbase/eventing/suptree.(*Supervisor).removeService.func1.1(0xdbd380, 0xc425ff8000, 0xc424954780, 0xb3, 0xc425405080)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/suptree/supervisor.go:413 +0x31

created by github.com/couchbase/eventing/suptree.(*Supervisor).removeService.func1

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/suptree/supervisor.go:412 +0xa3

2018-08-24T18:52:10.879-07:00 [Info] Consumer::processReqStreamMessages [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Exiting streamReq processing routine

2018-08-24T18:52:10.879-07:00 [Info] client::Stop [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Exiting c++ worker

2018-08-24T18:52:10.879-07:00 [Info] client::Stop [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Exiting c++ worker

2018-08-24T18:52:10.879-07:00 [Info] Consumer::processReqStreamMessages [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Exiting streamReq processing routine

2018-08-24T18:52:10.879-07:00 [Info] Consumer::Stop [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Stopped checkpoint, restart vb dcp stream and stats tickers

2018-08-24T18:52:10.879-07:00 [Info] Consumer::sendMessageLoop [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Exiting send message routine

2018-08-24T18:52:10.879-07:00 [Error] Consumer::Stop [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Consumer stop routine, recover runtime error: index out of range stack trace: goroutine 153934 [running]:

runtime/debug.Stack(0xc4257d4a40, 0xbeb780, 0x14cd380)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.10.3/go/src/runtime/debug/stack.go:24 +0xa7

github.com/couchbase/eventing/consumer.(*Consumer).Stop.func1(0xd056e8, 0xe, 0xc424aeca80)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/consumer/v8_consumer.go:368 +0x6e

panic(0xbeb780, 0x14cd380)

        /home/couchbase/.cbdepscache/exploded/x86_64/go-1.10.3/go/src/runtime/panic.go:502 +0x229

github.com/couchbase/eventing/consumer.(*Consumer).Stop(0xc424aeca80)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/consumer/v8_consumer.go:442 +0x194c

github.com/couchbase/eventing/suptree.(*Supervisor).removeService.func1.1(0xdbd380, 0xc424aeca80, 0xc4249540c0, 0xb3, 0xc42b2cbe60)

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/suptree/supervisor.go:413 +0x31

created by github.com/couchbase/eventing/suptree.(*Supervisor).removeService.func1

        /home/couchbase/jenkins/workspace/couchbase-server-unix/goproj/src/github.com/couchbase/eventing/suptree/supervisor.go:412 +0xa3

2018-08-24T18:52:10.879-07:00 [Info] client::Stop [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Exiting c++ worker

2018-08-24T18:52:10.879-07:00 [Info] Consumer::processReqStreamMessages [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Exiting streamReq processing routine

2018-08-24T18:52:10.894-07:00 [Warn] client::Serve [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Failed to read from stderr pipe, err: EOF

2018-08-24T18:52:10.894-07:00 [Warn] client::Serve [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Failed to read from stdout pipe, err: EOF

2018-08-24T18:52:10.895-07:00 [Warn] client::Serve [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] Exiting c++ worker with error: signal: killed

2018-08-24T18:52:10.895-07:00 [Info] client::Serve [worker_bucket_op_function_1:/tmp/127.0.0.1:8091_worker_bucket_op_function_1.sock:20440] After worker exit, stopCalled: true

2018-08-24T18:52:10.910-07:00 [Warn] client::Serve [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Failed to read from stderr pipe, err: EOF

2018-08-24T18:52:10.910-07:00 [Warn] client::Serve [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Failed to read from stdout pipe, err: EOF

2018-08-24T18:52:10.911-07:00 [Warn] client::Serve [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] Exiting c++ worker with error: signal: killed

2018-08-24T18:52:10.911-07:00 [Info] client::Serve [worker_bucket_op_function_2:/tmp/127.0.0.1:8091_worker_bucket_op_function_2.sock:20434] After worker exit, stopCalled: true

2018-08-24T18:52:10.918-07:00 [Info] DCPT[eventing:tbahHeMq-323:{eventing:tbahHeMq-322:172.23.96.168:8096_172.23.96.148:11210_worker_bucket_op_function_0}/0] Opaque: 2459342848 received NOOP from producer ...

2018-08-24T18:52:10.918-07:00 [Info] DCPT[eventing:tbahHeMq-323:{eventing:tbahHeMq-322:172.23.96.168:8096_172.23.96.148:11210_worker_bucket_op_function_0}/0] Opaque: 2459342848 responded to NOOP ok ...

2018-08-24T18:52:10.966-07:00 [Warn] client::Serve [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Failed to read from stderr pipe, err: EOF

2018-08-24T18:52:10.966-07:00 [Warn] client::Serve [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Failed to read from stdout pipe, err: EOF

2018-08-24T18:52:10.967-07:00 [Warn] client::Serve [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] Exiting c++ worker with error: signal: killed

2018-08-24T18:52:10.967-07:00 [Info] client::Serve [worker_bucket_op_function_0:/tmp/127.0.0.1:8091_worker_bucket_op_function_0.sock:20439] After worker exit, stopCalled: true

2018-08-24T18:52:11.735-07:00 [Info] DCPT[eventing:tbahHeMq-331:{eventing:tbahHeMq-330:172.23.96.168:8096_172.23.108.103:11210_worker_bucket_op_function_0}/0] dcp latency stats {"samples": 921628, "min": 0, "max": 1005498761, "mean": 2.213591319810162e+06, "variance": 8.680512193984394e+13}