Skip to content

Instantly share code, notes, and snippets.

@weilliu

weilliu/gist:2c2c9fa0170aa9e5eee5

Created August 31, 2015 22:20
Show Gist options
  • Save weilliu/2c2c9fa0170aa9e5eee5 to your computer and use it in GitHub Desktop.
Save weilliu/2c2c9fa0170aa9e5eee5 to your computer and use it in GitHub Desktop.
Download ZIP
swap index node log
Raw
gistfile1.txt
[root@centos-64-x64 sdkdclient-ng]# ./brun -I ../sdkd-cluster.args ../weili-vm.ini -A ../S3Creds_tmp --testsuite-variants "N1QL" --testsuite-test "Rb1SwapIndex[SingleService]" --testsuite-suite suites/SingleServiceN1QL.json --n1ql-nthreads 1 --n1ql-index-engine view --n1ql-index-type primary --n1ql-prepared false --n1ql-parameterized true -d all:debug --ramp=10 --no-upload
[0.21 INFO] (BRun run:457) Initializing history database
[0.93 DEBUG] (Nodelist <init>:364) Number of active nodes 4
============================================================
Running Rb1SwapIndex[SingleService]-N1QL
rebalance/count=1
workload=N1QLWorkloadGroup
rebalance/mode=swap
rebalance/services=index
testcase=RebalanceScenario
Logging to /root/sdkd-2.0/sdkdclient-ng/log/SDK-SDK/CB-4.0.0-4047-enterprise/Rb1SwapIndex[SingleService]-N1QL/08-31-15/080224/8650f859b69615c4da54150482b738be
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 \
--rebalance-count 1 --workload N1QLWorkloadGroup --rebalance-mode \
swap --rebalance-services index --testcase RebalanceScenario \
--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.04 WARN] (Drivers getDriver:76) 'rexec' is now mapped to *local* execution only. Use RemoteExecutingDriver for remote execution
[1.16 DEBUG] (Nodelist <init>:364) Number of active nodes 4
[1.16 INFO] (NodelistBuilder reserveFree:150) ret [http://172.23.105.194:8091]
[1.16 DEBUG] (NodelistBuilder reserveForRemoval:84) ret [http://172.23.106.87:8091]
[1.32 INFO] (RunContext run:104) Starting cluster and driver
[1.32 INFO] (HostPortDriver launch:32) Invoking SDKD as '/root/sdkd-2.0/run-sdkd-java'
[1.32 INFO] (CBCluster startCluster:386) Node http://172.23.105.174:8091 is master now
[1.32 DEBUG] (CBCluster startCluster:392) Stopping any existing rebalance operations..
[1.34 INFO] (SDKD log:137) ++ pgrep -f 'java.+-jar.*sdkd-java'
[1.34 INFO] (SDKD log:137) ++ dirname /root/sdkd-2.0/run-sdkd-java
[1.35 INFO] (SDKD log:137) + SDKD_ROOT=/root/sdkd-2.0
[1.35 INFO] (SDKD log:137) + cd /root/sdkd-2.0
[1.35 INFO] (SDKD log:137) + JAR=
[1.35 INFO] (SDKD log:137) + JAR_DEFAULT=
[1.35 INFO] (SDKD log:137) + '[' -z '' ']'
[1.35 INFO] (SDKD log:137) + JAR_DEFAULT=1
[1.35 INFO] (SDKD log:137) + JAR=/root/sdkd-2.0/sdkd_exec.jar
[1.35 INFO] (SDKD log:137) + '[' '!' -e /root/sdkd-2.0/sdkd_exec.jar ']'
[1.35 INFO] (SDKD log:137) + '[' '!' -e /root/sdkd-2.0/sdkd_exec.jar ']'
[1.35 INFO] (SDKD log:137) + java -ea -jar /root/sdkd-2.0/sdkd_exec.jar -l 8050 -shared 100 -sync true
[1.85 DEBUG] (Handle sendMessageAsync:183) > INFO@0.0
[1.94 DEBUG] (Handle receiveMessage:158) < INFO@0.0 => {"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.78 DEBUG] (CBCluster clearSingleCluster:142) Failing over existing and ejecting node <URI:172.23.105.194:8091,ns_1@172.23.105.194>
[3.84 DEBUG] (CBCluster clearSingleCluster:142) Failing over existing and ejecting node <URI:172.23.106.88:8091,ns_1@172.23.106.88>
[3.91 DEBUG] (SSHConnection initUserKeys:79) Loaded indentity /root/.ssh/id_rsa
[3.91 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84]
[3.91 DEBUG] (SSHConnection initUserKeys:79) Loaded indentity /root/.ssh/id_rsa
[3.91 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84]
[3.92 DEBUG] (SSHConnection initUserKeys:79) Loaded indentity /root/.ssh/id_rsa
[3.92 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84]
[3.92 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84]
[4.31 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.105.174:8091
[4.31 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.105.194:8091
[4.32 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.106.87:8091
[4.33 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
[4.33 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
[4.33 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
[4.34 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.106.88:8091
[4.34 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
[4.44 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@51d600f3
[4.44 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@1ccd906b
[4.54 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@35e03364
[4.72 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@445ebf6d
[4.73 DEBUG] (CBCluster setupNewCluster:290) Provisioning initial node com.couchbase.cbadmin.client.CouchbaseAdmin@d2c1351
[10.28 INFO] (CBCluster tryOnce:307) Adding node with services index
[14.31 INFO] (CBCluster tryOnce:307) Adding node with services n1ql
[20.14 INFO] (CBCluster setupNewCluster:314) All nodes added. Will rebalance
[20.17 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 0%
[21.18 INFO] (RebalanceWaiter sweepOnce:33) Rebalance complete
[21.18 DEBUG] (CBCluster setupServerGroups:241) Not creating any groups
[21.18 INFO] (CBCluster setupMainBucket:228) Creating bucket default
[21.20 INFO] (CBCluster setupMainBucket:230) Bucket creation submitted
[26.42 INFO] (CBCluster waitForBucketReady:222) Bucket creation done
[26.45 INFO] (RunContext run:204) Driver and cluster initialized
[26.45 INFO] (RunContext run:209) Ramp for 10 seconds. Cluster modification: add 1 nodes and remove 1nodes and rebalance. Rebound for 90 seconds.
[26.47 INFO] (RunContext call:260) Running scenario..
[26.47 INFO] (Scenario run:72) Starting RAMP phase
[26.47 DEBUG] (Handle sendMessageAsync:183) > NEWHANDLE@101.1 => {Options={OtherNodes=[["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}
[26.51 INFO] (SDKD log:137) Aug 31, 2015 3:17:29 PM com.couchbase.client.core.CouchbaseCore <init>
[26.51 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}
[27.03 INFO] (SDKD log:137) Aug 31, 2015 3:17:30 PM com.couchbase.client.core.node.CouchbaseNode$1 call
[27.03 INFO] (SDKD log:137) INFO: Connected to Node 172.23.105.174
[27.42 INFO] (SDKD log:137) Aug 31, 2015 3:17:30 PM com.couchbase.client.core.config.DefaultConfigurationProvider$6 call
[27.42 INFO] (SDKD log:137) INFO: Opened bucket default
[27.45 INFO] (SDKD log:137) Aug 31, 2015 3:17:30 PM com.couchbase.client.core.node.CouchbaseNode$1 call
[27.45 INFO] (SDKD log:137) INFO: Connected to Node 172.23.106.88
[27.47 DEBUG] (Handle receiveMessage:158) < NEWHANDLE@101.1
[27.48 DEBUG] (Handle sendMessageAsync:183) > CB_N1QL_CREATE_INDEX@101.2 => {NQIndexEngine=view, NQIndexType=primary, TimeRes=1, NQParamValues=n1ql,n1qldoc, NQDefaultIndexName=idx1, NQParam=tag,type}
[27.49 INFO] (SDKD log:137) Aug 31, 2015 3:17:30 PM com.couchbase.sdkd.cbclient.N1QLIndexCommandContext execIter
[27.50 INFO] (SDKD log:137) INFO: n1ql index: null
[32.83 DEBUG] (Handle receiveMessage:158) < CB_N1QL_CREATE_INDEX@101.2 => {"Timings":{"Step":1,"Windows":[{"Errors":{"0":1},"Min":1,"Avg":1,"Max":1,"Count":1}],"Base":1226498},"Summary":{"0":1}}
[32.84 DEBUG] (Handle sendMessageAsync:183) > CLOSEHANDLE@101.3
[32.84 DEBUG] (Handle sendMessageAsync:183) > NEWHANDLE@102.4 => {Options={OtherNodes=[["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}
[32.84 INFO] (SDKD log:137) Aug 31, 2015 3:17:35 PM com.couchbase.sdkd.server.SdkServer shutdown
[32.84 INFO] (SDKD log:137) WARNING: Shutting Down..
[32.84 DEBUG] (Handle receiveMessage:158) < NEWHANDLE@102.4
[32.84 DEBUG] (Handle sendMessageAsync:183) > CB_N1QL_QUERY@102.5 => {NQIndexEngine=view, NQIndexType=primary, NQScanConsistency=request_plus, NQParameterized=true, TimeRes=1, NQParamValues=n1ql,n1qldoc, NQDefaultIndexName=idx1, NQParam=tag,type, NQPrepared=false}
[32.84 INFO] (Scenario run:83) RAMP phase started. Waiting for 10 seconds
[32.85 INFO] (SDKD log:137) Aug 31, 2015 3:17:35 PM com.couchbase.sdkd.cbclient.N1QLQueryCommandContext execIter
[32.85 INFO] (SDKD log:137) INFO: Running n1ql query: SELECT * from default WHERE tag = "n1ql" AND type = "n1qldoc";
[32.85 INFO] (SDKD log:137) Aug 31, 2015 3:17:35 PM com.couchbase.sdkd.cbclient.N1QLQueryCommandContext execIter
[32.85 INFO] (SDKD log:137) INFO: n1ql drop_index: DROP INDEX `default`.`#primary`;
[42.84 INFO] (Scenario run:86) Starting CHANGE phase
[42.84 DEBUG] (CBCluster addNodes:547) Adding nodes [http://172.23.105.194:8091]
[47.03 DEBUG] (CBCluster removeAndRebalance:568) Removing Nodes [http://172.23.106.87:8091]
[47.11 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 0%
[48.12 INFO] (RebalanceWaiter sweepOnce:33) Rebalance complete
[48.12 INFO] (Scenario run:97) CHANGE phase done
[48.12 INFO] (Scenario run:103) Starting REBOUND for 90 seconds
[138.12 INFO] (Scenario run:105) REBOUND done. Will collect results
[138.12 DEBUG] (Handle sendMessageAsync:183) > CANCEL@102.5
[138.12 INFO] (SDKD log:137) Aug 31, 2015 3:19:21 PM com.couchbase.sdkd.server.SdkServer shutdown
[138.12 DEBUG] (Handle receiveMessage:158) < CANCEL@102.5
[138.12 INFO] (SDKD log:137) WARNING: Shutting Down..
[138.18 DEBUG] (Handle receiveMessage:158) < CB_N1QL_QUERY@102.5 => {[OK]: 23418} (tms: 106s)
[138.19 DEBUG] (Handle sendMessageAsync:183) > CLOSEHANDLE@102.6
[138.19 INFO] (Scenario run:117) Results collected. DONE
[138.19 INFO] (RunContext run:308) Closing SDKD Handles
[138.19 DEBUG] (Handle sendMessageAsync:183) > GOODBYE@0.7
[138.19 DEBUG] (Handle sendMessageAsync:183) > CLOSEHANDLE@100.8
[138.19 INFO] (HostPortDriver stop:123) SDKD is not yet terminated. Terminating..
[138.19 INFO] (SDKD log:137) Aug 31, 2015 3:19:21 PM com.couchbase.sdkd.server.SdkServer shutdown
[138.19 INFO] (HostPortDriver terminate:44) Waiting for process termination..
[138.19 INFO] (SDKD log:137) WARNING: Shutting Down..
[138.20 INFO] (SDKD log:137) Aug 31, 2015 3:19:21 PM com.couchbase.sdkd.server.SdkServer shutdown
[138.20 INFO] (SDKD log:137) WARNING: Shutting Down..
[138.20 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]
[138.55 ERROR] (HostPortDriver stop:135) SDKD terminated with error 143
[138.66 INFO] (CouchbaseCore info:121) CouchbaseEnvironment: {sslEnabled=false, sslKeystoreFile='null', sslKeystorePassword='null', 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-java-client/2.1.3 (git: 2.1.3), 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, queryTimeout=75000, viewTimeout=75000, kvTimeout=2500, connectTimeout=5000, disconnectTimeout=25000, dnsSrvEnabled=false}
[139.20 INFO] (Node info:121) Connected to Node 172.23.105.177
[139.65 INFO] (ConfigurationProvider info:121) Opened bucket situational
[root@centos-64-x64 sdkdclient-ng]#
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment