Skip to content

Instantly share code, notes, and snippets.

@weilliu

weilliu/gist:9296b8abd004cdeb09eb

Created August 31, 2015 22:44
Show Gist options

  • Select an option

    Learn more about clone URLs
  • Save weilliu/9296b8abd004cdeb09eb to your computer and use it in GitHub Desktop.

Select an option

Learn more about clone URLs
Save weilliu/9296b8abd004cdeb09eb to your computer and use it in GitHub Desktop.
Download ZIP
server restart index node log
Raw
gistfile1.txt
============================================================
Running SvcRestart[SingleService]-N1QL
workload=N1QLWorkloadGroup
service/action=kill
service/restore_delay=5
service/name=SYSV_SERVICE
testcase=ServiceFailureScenario
service/count=2
Logging to /root/sdkd-2.0/sdkdclient-ng/log/SDK-SDK/CB-4.0.0-4047-enterprise/SvcRestart[SingleService]-N1QL/08-31-15/081560/947dd4558a8fa1944b423858c82fcf00
To re-run the test, copy/paste the following into the shell.
You may also copy/paste (except the first line) into an argfile
8<----------------------------------------
./stester \
--workload N1QLWorkloadGroup --service-action kill \
--service-restore_delay 5 --service-name SYSV_SERVICE --testcase \
ServiceFailureScenario --service-count 2 \
--cluster_node=172.23.106.87:::index \
--cluster_node=172.23.106.88:::n1ql \
--cluster_node=172.23.105.194:::index \
--cluster_node=172.23.105.174:::kv --cluster_ssh-username=root \
--cluster_ssh-password=couchbase -C share/rexec --rexec_path \
/root/sdkd-2.0/run-sdkd-java --rexec_port 8050 --n1ql-nthreads 1 \
--n1ql-index-engine view --n1ql-index-type primary \
--n1ql-prepared false --n1ql-parameterized true --ramp=10
---------------------------------------->8
[1.11 WARN] (Drivers getDriver:76) 'rexec' is now mapped to *local* execution only. Use RemoteExecutingDriver for remote execution
[1.24 DEBUG] (Nodelist <init>:364) Number of active nodes 4
[1.38 INFO] (RunContext run:104) Starting cluster and driver
[1.39 INFO] (HostPortDriver launch:32) Invoking SDKD as '/root/sdkd-2.0/run-sdkd-java'
[1.39 INFO] (CBCluster startCluster:386) Node http://172.23.105.174:8091 is master now
[1.39 DEBUG] (CBCluster startCluster:392) Stopping any existing rebalance operations..
[1.40 INFO] (SDKD log:137) ++ pgrep -f 'java.+-jar.*sdkd-java'
[1.42 INFO] (SDKD log:137) ++ dirname /root/sdkd-2.0/run-sdkd-java
[1.42 INFO] (SDKD log:137) + SDKD_ROOT=/root/sdkd-2.0
[1.42 INFO] (SDKD log:137) + cd /root/sdkd-2.0
[1.42 INFO] (SDKD log:137) + JAR=
[1.42 INFO] (SDKD log:137) + JAR_DEFAULT=
[1.42 INFO] (SDKD log:137) + '[' -z '' ']'
[1.42 INFO] (SDKD log:137) + JAR_DEFAULT=1
[1.42 INFO] (SDKD log:137) + JAR=/root/sdkd-2.0/sdkd_exec.jar
[1.42 INFO] (SDKD log:137) + '[' '!' -e /root/sdkd-2.0/sdkd_exec.jar ']'
[1.42 INFO] (SDKD log:137) + '[' '!' -e /root/sdkd-2.0/sdkd_exec.jar ']'
[1.43 INFO] (SDKD log:137) + java -ea -jar /root/sdkd-2.0/sdkd_exec.jar -l 8050 -shared 100 -sync true
[1.91 DEBUG] (Handle sendMessageAsync:183) > [email protected]
[2.00 DEBUG] (Handle receiveMessage:158) < [email protected] => {"COMPONENTS":{"Core_VERSION":"couchbase-jvm-core/1.2.0-SNAPSHOT (git: 1.1.2-78-g0d14c71)","SDK_VERSION":"couchbase-java-client/2.2.0-SNAPSHOT (git: 2.1.2-71-g9891310) (Linux/2.6.32-358.el6.x86_64 amd64; Java HotSpot(TM) 64-Bit Server VM 1.8.0_25-b17)"},"CAPS":{"VIEWS":true,"OBS":true,"DS_SHARED":true,"CANCEL":true,"CONTINUOUS":true,"TTL":true,"PREAMBLE":false}}
[3.05 DEBUG] (CBCluster clearSingleCluster:142) Failing over existing and ejecting node <URI:172.23.105.194:8091,[email protected]>
[3.10 DEBUG] (CBCluster clearSingleCluster:142) Failing over existing and ejecting node <URI:172.23.106.87:8091,[email protected]>
[3.13 DEBUG] (CBCluster clearSingleCluster:142) Failing over existing and ejecting node <URI:172.23.106.88:8091,[email protected]>
[3.21 DEBUG] (SSHConnection initUserKeys:79) Loaded indentity /root/.ssh/id_rsa
[3.21 DEBUG] (SSHConnection initUserKeys:79) Loaded indentity /root/.ssh/id_rsa
[3.21 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84]
[3.21 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84]
[3.61 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.106.87:8091
[3.61 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.105.174:8091
[3.61 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.105.194:8091
[3.62 DEBUG] (SSHCommand execute:75) Running /etc/init.d/couchbase-server start && pkill -CONT -f memcached && pkill -CONT -f beam.smp && iptables -F && iptables -t nat -F on 172.23.105.174
[3.62 DEBUG] (SSHCommand execute:75) Running /etc/init.d/couchbase-server start && pkill -CONT -f memcached && pkill -CONT -f beam.smp && iptables -F && iptables -t nat -F on 172.23.106.87
[3.62 DEBUG] (SSHCommand execute:75) Running /etc/init.d/couchbase-server start && pkill -CONT -f memcached && pkill -CONT -f beam.smp && iptables -F && iptables -t nat -F on 172.23.105.194
[3.64 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.106.88:8091
[3.64 DEBUG] (SSHCommand execute:75) Running /etc/init.d/couchbase-server start && pkill -CONT -f memcached && pkill -CONT -f beam.smp && iptables -F && iptables -t nat -F on 172.23.106.88
[3.73 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@5d4b3038
[3.73 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@6ac141d4
[3.83 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@2c47f10c
[4.07 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@e97d817
[4.07 DEBUG] (CBCluster setupNewCluster:290) Provisioning initial node com.couchbase.cbadmin.client.CouchbaseAdmin@719f3798
[13.65 INFO] (CBCluster tryOnce:307) Adding node with services index
[19.72 INFO] (CBCluster tryOnce:307) Adding node with services index
[23.83 INFO] (CBCluster tryOnce:307) Adding node with services n1ql
[28.15 INFO] (CBCluster setupNewCluster:314) All nodes added. Will rebalance
[28.19 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 0%
[29.20 INFO] (RebalanceWaiter sweepOnce:33) Rebalance complete
[29.20 DEBUG] (CBCluster setupServerGroups:241) Not creating any groups
[29.20 INFO] (CBCluster setupMainBucket:228) Creating bucket default
[29.22 INFO] (CBCluster setupMainBucket:230) Bucket creation submitted
[34.85 INFO] (CBCluster waitForBucketReady:222) Bucket creation done
[34.89 INFO] (RunContext run:204) Driver and cluster initialized
[34.89 INFO] (RunContext run:209) Ramp for 10 seconds. Cluster modification: Execute '/etc/init.d/couchbase-server stop' on 2 nodes waiting 1 seconds between each invocation sleep for 5 seconds and restore the nodes. Restoring is peformed by: re-active the services by invoking /etc/init.d/couchbase-server starton each of the nodes. Rebound for 90 seconds.
[34.91 INFO] (RunContext call:260) Running scenario..
[34.91 INFO] (Scenario run:72) Starting RAMP phase
[34.92 DEBUG] (Handle sendMessageAsync:183) > [email protected] => {Options={OtherNodes=[["172.23.105.194",8091],["172.23.106.87",8091],["172.23.106.88",8091]], Username=default, ClusterCertificate=, SSL=false, Password=}, Bucket=default, Port=8091, Hostname=172.23.105.174}
[34.95 INFO] (SDKD log:137) Aug 31, 2015 3:39:54 PM com.couchbase.client.core.CouchbaseCore <init>
[34.95 INFO] (SDKD log:137) INFO: CouchbaseEnvironment: {sslEnabled=false, sslKeystoreFile='cacerts', sslKeystorePassword='couchbase', queryEnabled=false, queryPort=8093, bootstrapHttpEnabled=true, bootstrapCarrierEnabled=true, bootstrapHttpDirectPort=8091, bootstrapHttpSslPort=18091, bootstrapCarrierDirectPort=11210, bootstrapCarrierSslPort=11207, ioPoolSize=4, computationPoolSize=4, responseBufferSize=16384, requestBufferSize=16384, kvServiceEndpoints=1, viewServiceEndpoints=1, queryServiceEndpoints=1, ioPool=NioEventLoopGroup, coreScheduler=CoreScheduler, eventBus=DefaultEventBus, packageNameAndVersion=couchbase-jvm-core/1.2.0-SNAPSHOT (git: 1.1.2-78-g0d14c71), dcpEnabled=false, retryStrategy=BestEffort, maxRequestLifetime=75000, retryDelay=ExponentialDelay{growBy 1.0 MICROSECONDS; lower=100, upper=100000}, reconnectDelay=ExponentialDelay{growBy 1.0 MILLISECONDS; lower=32, upper=4096}, observeIntervalDelay=ExponentialDelay{growBy 1.0 MICROSECONDS; lower=10, upper=100000}, keepAliveInterval=30000, autoreleaseAfter=2000, bufferPoolingEnabled=true, tcpNodelayEnabled=true, mutationTokensEnabled=false, queryTimeout=75000, viewTimeout=15000, kvTimeout=2500, connectTimeout=5000, disconnectTimeout=25000, dnsSrvEnabled=false}
[35.51 INFO] (SDKD log:137) Aug 31, 2015 3:39:54 PM com.couchbase.client.core.node.CouchbaseNode$1 call
[35.51 INFO] (SDKD log:137) INFO: Connected to Node 172.23.105.174
[35.89 INFO] (SDKD log:137) Aug 31, 2015 3:39:54 PM com.couchbase.client.core.config.DefaultConfigurationProvider$6 call
[35.89 INFO] (SDKD log:137) INFO: Opened bucket default
[35.91 INFO] (SDKD log:137) Aug 31, 2015 3:39:54 PM com.couchbase.client.core.node.CouchbaseNode$1 call
[35.91 INFO] (SDKD log:137) INFO: Connected to Node 172.23.106.88
[35.94 DEBUG] (Handle receiveMessage:158) < [email protected]
[35.94 DEBUG] (Handle sendMessageAsync:183) > [email protected] => {NQIndexEngine=view, NQIndexType=primary, TimeRes=1, NQParamValues=n1ql,n1qldoc, NQDefaultIndexName=idx1, NQParam=tag,type}
[35.96 INFO] (SDKD log:137) Aug 31, 2015 3:39:55 PM com.couchbase.sdkd.cbclient.N1QLIndexCommandContext execIter
[35.96 INFO] (SDKD log:137) INFO: n1ql index: null
[41.33 DEBUG] (Handle receiveMessage:158) < [email protected] => {"Timings":{"Step":1,"Windows":[{"Errors":{"0":1},"Min":1,"Avg":1,"Max":1,"Count":1}],"Base":1227842},"Summary":{"0":1}}
[41.33 DEBUG] (Handle sendMessageAsync:183) > [email protected]
[41.33 DEBUG] (Handle sendMessageAsync:183) > [email protected] => {Options={OtherNodes=[["172.23.105.194",8091],["172.23.106.87",8091],["172.23.106.88",8091]], Username=default, ClusterCertificate=, SSL=false, Password=}, Bucket=default, Port=8091, Hostname=172.23.105.174}
[41.33 INFO] (SDKD log:137) Aug 31, 2015 3:40:00 PM com.couchbase.sdkd.server.SdkServer shutdown
[41.33 INFO] (SDKD log:137) WARNING: Shutting Down..
[41.33 INFO] (SDKD log:137) Aug 31, 2015 3:40:00 PM com.couchbase.client.core.CouchbaseCore <init>
[41.34 INFO] (SDKD log:137) INFO: CouchbaseEnvironment: {sslEnabled=false, sslKeystoreFile='cacerts', sslKeystorePassword='couchbase', queryEnabled=false, queryPort=8093, bootstrapHttpEnabled=true, bootstrapCarrierEnabled=true, bootstrapHttpDirectPort=8091, bootstrapHttpSslPort=18091, bootstrapCarrierDirectPort=11210, bootstrapCarrierSslPort=11207, ioPoolSize=4, computationPoolSize=4, responseBufferSize=16384, requestBufferSize=16384, kvServiceEndpoints=1, viewServiceEndpoints=1, queryServiceEndpoints=1, ioPool=NioEventLoopGroup, coreScheduler=CoreScheduler, eventBus=DefaultEventBus, packageNameAndVersion=couchbase-jvm-core/1.2.0-SNAPSHOT (git: 1.1.2-78-g0d14c71), dcpEnabled=false, retryStrategy=BestEffort, maxRequestLifetime=75000, retryDelay=ExponentialDelay{growBy 1.0 MICROSECONDS; lower=100, upper=100000}, reconnectDelay=ExponentialDelay{growBy 1.0 MILLISECONDS; lower=32, upper=4096}, observeIntervalDelay=ExponentialDelay{growBy 1.0 MICROSECONDS; lower=10, upper=100000}, keepAliveInterval=30000, autoreleaseAfter=2000, bufferPoolingEnabled=true, tcpNodelayEnabled=true, mutationTokensEnabled=false, queryTimeout=75000, viewTimeout=15000, kvTimeout=2500, connectTimeout=5000, disconnectTimeout=25000, dnsSrvEnabled=false}
[41.39 INFO] (SDKD log:137) Aug 31, 2015 3:40:00 PM com.couchbase.client.core.node.CouchbaseNode$1 call
[41.39 INFO] (SDKD log:137) INFO: Connected to Node 172.23.105.174
[41.43 INFO] (SDKD log:137) Aug 31, 2015 3:40:00 PM com.couchbase.client.core.node.CouchbaseNode$1 call
[41.43 INFO] (SDKD log:137) INFO: Connected to Node 172.23.106.88
[41.43 INFO] (SDKD log:137) Aug 31, 2015 3:40:00 PM com.couchbase.client.core.config.DefaultConfigurationProvider$6 call
[41.43 INFO] (SDKD log:137) INFO: Opened bucket default
[41.44 DEBUG] (Handle receiveMessage:158) < [email protected]
[41.44 DEBUG] (Handle sendMessageAsync:183) > [email protected] => {NQIndexEngine=view, NQIndexType=primary, NQScanConsistency=request_plus, NQParameterized=true, TimeRes=1, NQParamValues=n1ql,n1qldoc, NQDefaultIndexName=idx1, NQParam=tag,type, NQPrepared=false}
[41.45 INFO] (Scenario run:83) RAMP phase started. Waiting for 10 seconds
[41.45 INFO] (SDKD log:137) Aug 31, 2015 3:40:00 PM com.couchbase.sdkd.cbclient.N1QLQueryCommandContext execIter
[41.45 INFO] (SDKD log:137) INFO: Running n1ql query: SELECT * from default WHERE tag = "n1ql" AND type = "n1qldoc";
[41.45 INFO] (SDKD log:137) Aug 31, 2015 3:40:00 PM com.couchbase.sdkd.cbclient.N1QLQueryCommandContext execIter
[41.45 INFO] (SDKD log:137) INFO: n1ql drop_index: DROP INDEX `default`.`#primary`;
[51.45 INFO] (Scenario run:86) Starting CHANGE phase
[51.45 DEBUG] (SSHCommand execute:75) Running /etc/init.d/couchbase-server stop on 172.23.105.194
[54.06 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@927cd
[55.06 DEBUG] (SSHCommand execute:75) Running /etc/init.d/couchbase-server stop on 172.23.106.87
[56.96 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@6e6e9767
[57.97 INFO] (Scenario sleepAndDo:109) Sleeping 5 seconds
[62.97 INFO] (Scenario executeChange:134) Turning on services for nodes
[62.97 DEBUG] (SSHCommand execute:75) Running /etc/init.d/couchbase-server start on 172.23.105.194
[64.48 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@5890ca88
[65.48 DEBUG] (SSHCommand execute:75) Running /etc/init.d/couchbase-server start on 172.23.106.87
[66.98 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@29e0719d
[67.99 INFO] (Scenario run:97) CHANGE phase done
[67.99 INFO] (Scenario run:103) Starting REBOUND for 90 seconds
[157.99 INFO] (Scenario run:105) REBOUND done. Will collect results
[157.99 DEBUG] (Handle sendMessageAsync:183) > [email protected]
[157.99 INFO] (SDKD log:137) Aug 31, 2015 3:41:57 PM com.couchbase.sdkd.server.SdkServer shutdown
[157.99 INFO] (SDKD log:137) WARNING: Shutting Down..
[157.99 DEBUG] (Handle receiveMessage:158) < [email protected]
[158.02 DEBUG] (Handle receiveMessage:158) < [email protected] => {[OK]: 25011} (tms: 118s)
[158.04 DEBUG] (Handle sendMessageAsync:183) > [email protected]
[158.04 INFO] (Scenario run:117) Results collected. DONE
[158.04 INFO] (RunContext run:308) Closing SDKD Handles
[158.04 DEBUG] (Handle sendMessageAsync:183) > [email protected]
[158.04 DEBUG] (Handle sendMessageAsync:183) > [email protected]
[158.04 INFO] (SDKD log:137) Aug 31, 2015 3:41:57 PM com.couchbase.sdkd.server.SdkServer shutdown
[158.04 INFO] (HostPortDriver stop:123) SDKD is not yet terminated. Terminating..
[158.04 INFO] (SDKD log:137) WARNING: Shutting Down..
[158.04 INFO] (HostPortDriver terminate:44) Waiting for process termination..
[158.05 ERROR] (LineGobbler err:160) Stream Error
java.io.IOException: Stream closed
at java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:170) ~[na:1.8.0_25]
at java.io.BufferedInputStream.read(BufferedInputStream.java:336) ~[na:1.8.0_25]
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284) ~[na:1.8.0_25]
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326) ~[na:1.8.0_25]
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178) ~[na:1.8.0_25]
at java.io.InputStreamReader.read(InputStreamReader.java:184) ~[na:1.8.0_25]
at java.io.BufferedReader.fill(BufferedReader.java:161) ~[na:1.8.0_25]
at java.io.BufferedReader.readLine(BufferedReader.java:324) ~[na:1.8.0_25]
at java.io.BufferedReader.readLine(BufferedReader.java:389) ~[na:1.8.0_25]
at com.couchbase.sdkdclient.util.LineGobbler.run(LineGobbler.java:76) ~[sdkdclient-1.0-SNAPSHOT.jar:na]
[158.40 ERROR] (HostPortDriver stop:135) SDKD terminated with error 143
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment