Created
August 31, 2015 21:38
-
-
Save weilliu/a39831fdfa0c73d6acfa to your computer and use it in GitHub Desktop.
reblance out 2 nodes log
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| ============================================================ | |
| Running Rb2Out-N1QL | |
| rebalance/count=2 | |
| workload=N1QLWorkloadGroup | |
| rebalance/mode=out | |
| testcase=RebalanceScenario | |
| Logging to /root/sdkd-2.0/sdkdclient-ng/log/SDK-SDK/CB-4.0.0-4047-enterprise/Rb2Out-N1QL/08-31-15/076917/2c91fb031a38689ac12358de7a984b7b | |
| 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 2 --workload N1QLWorkloadGroup --rebalance-mode \ | |
| out --testcase RebalanceScenario \ | |
| --cluster_node=172.23.106.87:::kv,index,n1ql \ | |
| --cluster_node=172.23.106.88:::kv,index,n1ql \ | |
| --cluster_node=172.23.105.194:::kv:index.n1ql \ | |
| --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 gsi --n1ql-index-type primary --n1ql-prepared \ | |
| true --n1ql-parameterized false --ramp=10 | |
| ---------------------------------------->8 | |
| [1.06 WARN] (Drivers getDriver:76) 'rexec' is now mapped to *local* execution only. Use RemoteExecutingDriver for remote execution | |
| [1.18 DEBUG] (Nodelist <init>:364) Number of active nodes 4 | |
| [1.18 DEBUG] (NodelistBuilder reserveForRemoval:84) ret [http://172.23.105.194:8091, http://172.23.106.87:8091] | |
| [1.33 INFO] (RunContext run:104) Starting cluster and driver | |
| [1.34 INFO] (HostPortDriver launch:32) Invoking SDKD as '/root/sdkd-2.0/run-sdkd-java' | |
| [1.34 INFO] (CBCluster startCluster:386) Node http://172.23.105.174:8091 is master now | |
| [1.34 DEBUG] (CBCluster startCluster:392) Stopping any existing rebalance operations.. | |
| [1.35 INFO] (SDKD log:137) ++ pgrep -f 'java.+-jar.*sdkd-java' | |
| [1.37 INFO] (SDKD log:137) ++ dirname /root/sdkd-2.0/run-sdkd-java | |
| [1.37 INFO] (SDKD log:137) + SDKD_ROOT=/root/sdkd-2.0 | |
| [1.37 INFO] (SDKD log:137) + cd /root/sdkd-2.0 | |
| [1.37 INFO] (SDKD log:137) + JAR= | |
| [1.37 INFO] (SDKD log:137) + JAR_DEFAULT= | |
| [1.37 INFO] (SDKD log:137) + '[' -z '' ']' | |
| [1.37 INFO] (SDKD log:137) + JAR_DEFAULT=1 | |
| [1.37 INFO] (SDKD log:137) + JAR=/root/sdkd-2.0/sdkd_exec.jar | |
| [1.37 INFO] (SDKD log:137) + '[' '!' -e /root/sdkd-2.0/sdkd_exec.jar ']' | |
| [1.37 INFO] (SDKD log:137) + '[' '!' -e /root/sdkd-2.0/sdkd_exec.jar ']' | |
| [1.37 INFO] (SDKD log:137) + java -ea -jar /root/sdkd-2.0/sdkd_exec.jar -l 8050 -shared 100 -sync true | |
| [1.86 DEBUG] (Handle sendMessageAsync:183) > INFO@0.0 | |
| [1.95 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.03 DEBUG] (CBCluster clearSingleCluster:142) Failing over existing and ejecting node <URI:172.23.105.194:8091,ns_1@172.23.105.194> | |
| [3.07 DEBUG] (CBCluster clearSingleCluster:142) Failing over existing and ejecting node <URI:172.23.106.88:8091,ns_1@172.23.106.88> | |
| [3.14 DEBUG] (SSHConnection initUserKeys:79) Loaded indentity /root/.ssh/id_rsa | |
| [3.14 DEBUG] (SSHConnection initUserKeys:79) Loaded indentity /root/.ssh/id_rsa | |
| [3.14 DEBUG] (SSHConnection initUserKeys:79) Loaded indentity /root/.ssh/id_rsa | |
| [3.14 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84] | |
| [3.14 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84] | |
| [3.14 DEBUG] (SSHConnection connect:99) Connecting with User[root] Pass[HASH=3b8cf05627127baaf3808913209aac84] | |
| [3.53 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.105.194:8091 | |
| [3.53 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.106.87:8091 | |
| [3.53 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.105.174:8091 | |
| [3.54 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.54 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.54 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.56 INFO] (NodeHost createSSH:160) SSH Initialized for http://172.23.106.88:8091 | |
| [3.56 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.65 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@2e43e17b | |
| [3.65 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@5c1a6256 | |
| [3.75 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@2f2b66c7 | |
| [3.97 DEBUG] (SSHCommand close:147) Closing channel com.jcraft.jsch.ChannelExec@726e4578 | |
| [3.97 DEBUG] (CBCluster setupNewCluster:290) Provisioning initial node com.couchbase.cbadmin.client.CouchbaseAdmin@40b34ec4 | |
| [13.04 INFO] (CBCluster tryOnce:307) Adding node with services kv,n1ql,index | |
| [17.68 INFO] (CBCluster tryOnce:307) Adding node with services kv,index,n1ql | |
| [21.69 INFO] (CBCluster tryOnce:307) Adding node with services kv,index,n1ql | |
| [25.85 INFO] (CBCluster setupNewCluster:314) All nodes added. Will rebalance | |
| [25.89 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 0% | |
| [26.89 INFO] (RebalanceWaiter sweepOnce:33) Rebalance complete | |
| [26.89 DEBUG] (CBCluster setupServerGroups:241) Not creating any groups | |
| [26.90 INFO] (CBCluster setupMainBucket:228) Creating bucket default | |
| [26.91 INFO] (CBCluster setupMainBucket:230) Bucket creation submitted | |
| [33.56 INFO] (CBCluster waitForBucketReady:222) Bucket creation done | |
| [33.59 INFO] (RunContext run:204) Driver and cluster initialized | |
| [33.59 INFO] (RunContext run:209) Ramp for 10 seconds. Cluster modification: remove 2 nodes and rebalance. Rebound for 90 seconds. | |
| [33.61 INFO] (RunContext call:260) Running scenario.. | |
| [33.62 INFO] (Scenario run:72) Starting RAMP phase | |
| [33.62 DEBUG] (Handle sendMessageAsync:183) > NEWHANDLE@101.1 => {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} | |
| [33.65 INFO] (SDKD log:137) Aug 31, 2015 2:22:30 PM com.couchbase.client.core.CouchbaseCore <init> | |
| [33.65 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} | |
| [34.16 INFO] (SDKD log:137) Aug 31, 2015 2:22:30 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [34.16 INFO] (SDKD log:137) INFO: Connected to Node 172.23.105.174 | |
| [34.56 INFO] (SDKD log:137) Aug 31, 2015 2:22:31 PM com.couchbase.client.core.config.DefaultConfigurationProvider$6 call | |
| [34.56 INFO] (SDKD log:137) INFO: Opened bucket default | |
| [34.63 INFO] (SDKD log:137) Aug 31, 2015 2:22:31 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [34.63 INFO] (SDKD log:137) INFO: Connected to Node 172.23.105.194 | |
| [34.65 INFO] (SDKD log:137) Aug 31, 2015 2:22:31 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [34.65 INFO] (SDKD log:137) INFO: Connected to Node 172.23.106.87 | |
| [34.65 DEBUG] (Handle receiveMessage:158) < NEWHANDLE@101.1 | |
| [34.65 DEBUG] (Handle sendMessageAsync:183) > CB_N1QL_CREATE_INDEX@101.2 => {NQIndexEngine=gsi, NQIndexType=primary, TimeRes=1, NQParamValues=n1ql,n1qldoc, NQDefaultIndexName=idx1, NQParam=tag,type} | |
| [34.66 INFO] (SDKD log:137) Aug 31, 2015 2:22:31 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [34.66 INFO] (SDKD log:137) INFO: Connected to Node 172.23.106.88 | |
| [34.67 INFO] (SDKD log:137) Aug 31, 2015 2:22:31 PM com.couchbase.sdkd.cbclient.N1QLIndexCommandContext execIter | |
| [34.67 INFO] (SDKD log:137) INFO: n1ql index: null | |
| [43.49 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":1223202},"Summary":{"0":1}} | |
| [43.49 DEBUG] (Handle sendMessageAsync:183) > CLOSEHANDLE@101.3 | |
| [43.49 DEBUG] (Handle sendMessageAsync:183) > NEWHANDLE@102.4 => {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} | |
| [43.49 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.sdkd.server.SdkServer shutdown | |
| [43.49 INFO] (SDKD log:137) WARNING: Shutting Down.. | |
| [43.49 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.client.core.CouchbaseCore <init> | |
| [43.49 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} | |
| [43.52 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [43.52 INFO] (SDKD log:137) INFO: Connected to Node 172.23.105.174 | |
| [43.58 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [43.58 INFO] (SDKD log:137) INFO: Connected to Node 172.23.105.194 | |
| [43.58 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.client.core.config.DefaultConfigurationProvider$6 call | |
| [43.58 INFO] (SDKD log:137) INFO: Opened bucket default | |
| [43.59 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [43.59 INFO] (SDKD log:137) INFO: Connected to Node 172.23.106.87 | |
| [43.59 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [43.59 INFO] (SDKD log:137) INFO: Connected to Node 172.23.106.88 | |
| [43.59 DEBUG] (Handle receiveMessage:158) < NEWHANDLE@102.4 | |
| [43.59 DEBUG] (Handle sendMessageAsync:183) > CB_N1QL_QUERY@102.5 => {NQIndexEngine=gsi, NQIndexType=primary, NQScanConsistency=request_plus, NQParameterized=false, TimeRes=1, NQParamValues=n1ql,n1qldoc, NQDefaultIndexName=idx1, NQParam=tag,type, NQPrepared=true} | |
| [43.60 INFO] (Scenario run:83) RAMP phase started. Waiting for 10 seconds | |
| [43.60 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.sdkd.cbclient.N1QLQueryCommandContext execIter | |
| [43.60 INFO] (SDKD log:137) INFO: Running n1ql query: SELECT * from default WHERE tag = "n1ql" AND type = "n1qldoc"; | |
| [43.60 INFO] (SDKD log:137) Aug 31, 2015 2:22:40 PM com.couchbase.sdkd.cbclient.N1QLQueryCommandContext execIter | |
| [43.60 INFO] (SDKD log:137) INFO: n1ql drop_index: DROP INDEX `default`.`#primary` using gsi; | |
| [53.60 INFO] (Scenario run:86) Starting CHANGE phase | |
| [53.60 DEBUG] (CBCluster removeAndRebalance:568) Removing Nodes [http://172.23.105.194:8091, http://172.23.106.87:8091] | |
| [53.67 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 0% | |
| [54.70 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 0% | |
| [55.71 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 2% | |
| [56.72 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 4% | |
| [57.74 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 6% | |
| [58.76 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 8% | |
| [59.76 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 11% | |
| [60.77 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 13% | |
| [61.78 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 16% | |
| [62.81 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 18% | |
| [63.83 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 20% | |
| [64.83 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 22% | |
| [65.84 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 25% | |
| [66.85 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 27% | |
| [67.87 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 29% | |
| [68.89 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 31% | |
| [69.92 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 33% | |
| [70.92 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 35% | |
| [71.93 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 38% | |
| [72.95 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 40% | |
| [73.99 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 42% | |
| [75.00 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 44% | |
| [76.01 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 46% | |
| [77.02 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 48% | |
| [78.03 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 51% | |
| [79.05 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 53% | |
| [80.06 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 55% | |
| [81.41 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 57% | |
| [82.43 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 59% | |
| [83.44 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 62% | |
| [84.46 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 64% | |
| [85.47 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 66% | |
| [86.49 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 68% | |
| [87.50 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 70% | |
| [88.51 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 72% | |
| [89.52 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 74% | |
| [90.63 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 76% | |
| [92.20 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 78% | |
| [93.22 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 79% | |
| [94.27 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 81% | |
| [95.28 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 82% | |
| [96.30 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 84% | |
| [97.31 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 86% | |
| [98.32 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 87% | |
| [99.35 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 89% | |
| [100.36 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 90% | |
| [101.37 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 92% | |
| [102.39 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 93% | |
| [103.41 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 95% | |
| [104.42 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 97% | |
| [105.44 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 98% | |
| [106.45 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [107.45 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [108.46 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [109.46 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [110.47 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [111.47 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [112.48 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [113.48 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [114.49 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [115.49 DEBUG] (RebalanceWaiter sweepOnce:38) Rebalance Progress: 100% | |
| [116.39 INFO] (SDKD log:137) Exception in thread "SDK Handle-102: CMD [CB_N1QL_QUERY] " com.couchbase.client.core.RequestCancelledException: Request cancelled in-flight. | |
| [116.40 INFO] (LineGobbler doFilter:115) +++ Following exception has internal ID: 1 | |
| [116.40 INFO] (SDKD log:137) at com.couchbase.client.core.endpoint.AbstractGenericHandler.handleOutstandingOperations(AbstractGenericHandler.java:339) | |
| at com.couchbase.client.core.endpoint.AbstractGenericHandler.handlerRemoved(AbstractGenericHandler.java:320) | |
| at com.couchbase.client.core.endpoint.query.QueryHandler.handlerRemoved(QueryHandler.java:613) | |
| at com.couchbase.client.deps.io.netty.channel.DefaultChannelPipeline.callHandlerRemoved0(DefaultChannelPipeline.java:527) | |
| at com.couchbase.client.deps.io.netty.channel.DefaultChannelPipeline.callHandlerRemoved(DefaultChannelPipeline.java:521) | |
| at com.couchbase.client.deps.io.netty.channel.DefaultChannelPipeline.remove0(DefaultChannelPipeline.java:351) | |
| at com.couchbase.client.deps.io.netty.channel.DefaultChannelPipeline.destroyDown(DefaultChannelPipeline.java:798) | |
| at com.couchbase.client.deps.io.netty.channel.DefaultChannelPipeline.destroyUp(DefaultChannelPipeline.java:767) | |
| at com.couchbase.client.deps.io.netty.channel.DefaultChannelPipeline.destroy(DefaultChannelPipeline.java:759) | |
| at com.couchbase.client.deps.io.netty.channel.DefaultChannelPipeline.fireChannelUnregistered(DefaultChannelPipeline.java:743) | |
| at com.couchbase.client.deps.io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:659) | |
| at com.couchbase.client.deps.io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:356) | |
| at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) | |
| at com.couchbase.client.deps.io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:110) | |
| at com.couchbase.client.deps.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137) | |
| at java.lang.Thread.run(Thread.java:745) | |
| [116.40 INFO] (SDKD log:137) Aug 31, 2015 2:23:53 PM com.couchbase.client.core.endpoint.AbstractEndpoint$2 operationComplete | |
| [116.40 INFO] (SDKD log:137) WARNING: [/172.23.105.194:8093][QueryEndpoint]: Could not connect to endpoint, retrying with delay 32 MILLISECONDS: | |
| [116.40 INFO] (SDKD log:137) java.net.ConnectException: Connection refused: /172.23.105.194:8093 | |
| [116.40 INFO] (LineGobbler doFilter:115) +++ Following exception has internal ID: 3 | |
| [116.40 INFO] (SDKD log:137) at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) | |
| at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:716) | |
| at com.couchbase.client.deps.io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:224) | |
| at com.couchbase.client.deps.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:289) | |
| at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:528) | |
| at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468) | |
| at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382) | |
| at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354) | |
| at com.couchbase.client.deps.io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:110) | |
| at com.couchbase.client.deps.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137) | |
| at java.lang.Thread.run(Thread.java:745) | |
| [116.40 INFO] (SDKD log:137) | |
| [116.40 INFO] (SDKD log:137) Aug 31, 2015 2:23:53 PM com.couchbase.client.core.endpoint.AbstractEndpoint$2 operationComplete | |
| [116.40 INFO] (SDKD log:137) WARNING: [/172.23.105.194:8093][QueryEndpoint]: Could not connect to endpoint, retrying with delay 32 MILLISECONDS: | |
| [116.40 INFO] (SDKD log:137) java.net.ConnectException: Connection refused: /172.23.105.194:8093 | |
| [116.40 INFO] (SDKD log:137) +++ Received exception of ID 2 | |
| [116.40 INFO] (SDKD log:137) | |
| [116.40 INFO] (SDKD log:137) Aug 31, 2015 2:23:53 PM com.couchbase.client.core.endpoint.AbstractEndpoint$2 operationComplete | |
| [116.40 INFO] (SDKD log:137) WARNING: [/172.23.106.87:8093][QueryEndpoint]: Could not connect to endpoint, retrying with delay 32 MILLISECONDS: | |
| [116.41 INFO] (SDKD log:137) java.net.ConnectException: Connection refused: /172.23.106.87:8093 | |
| [116.41 INFO] (SDKD log:137) +++ Received exception of ID 2 | |
| [116.41 INFO] (SDKD log:137) | |
| [116.41 INFO] (SDKD log:137) Aug 31, 2015 2:23:53 PM com.couchbase.client.core.endpoint.AbstractEndpoint$2 operationComplete | |
| [116.41 INFO] (SDKD log:137) WARNING: [/172.23.106.87:8093][QueryEndpoint]: Could not connect to endpoint, retrying with delay 32 MILLISECONDS: | |
| [116.41 INFO] (SDKD log:137) java.net.ConnectException: Connection refused: /172.23.106.87:8093 | |
| [116.41 INFO] (SDKD log:137) +++ Received exception of ID 2 | |
| [116.41 INFO] (SDKD log:137) | |
| [116.41 INFO] (SDKD log:137) Aug 31, 2015 2:23:53 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [116.41 INFO] (SDKD log:137) INFO: Disconnected from Node 172.23.105.194 | |
| [116.42 INFO] (SDKD log:137) Aug 31, 2015 2:23:53 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [116.42 INFO] (SDKD log:137) INFO: Disconnected from Node 172.23.105.194 | |
| [116.42 INFO] (SDKD log:137) Aug 31, 2015 2:23:53 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [116.42 INFO] (SDKD log:137) INFO: Disconnected from Node 172.23.106.87 | |
| [116.42 INFO] (SDKD log:137) Aug 31, 2015 2:23:53 PM com.couchbase.client.core.node.CouchbaseNode$1 call | |
| [116.43 INFO] (SDKD log:137) INFO: Disconnected from Node 172.23.106.87 | |
| [116.50 INFO] (RebalanceWaiter sweepOnce:33) Rebalance complete | |
| [116.50 INFO] (Scenario run:97) CHANGE phase done | |
| [116.50 INFO] (Scenario run:103) Starting REBOUND for 90 seconds | |
| [206.51 INFO] (Scenario run:105) REBOUND done. Will collect results | |
| [206.51 DEBUG] (Handle sendMessageAsync:183) > CANCEL@102.5 | |
| [206.51 INFO] (SDKD log:137) Aug 31, 2015 2:25:23 PM com.couchbase.sdkd.server.SdkServer shutdown | |
| [206.51 INFO] (SDKD log:137) WARNING: Shutting Down.. | |
| [206.51 INFO] (SDKD log:137) Aug 31, 2015 2:25:23 PM com.couchbase.sdkd.server.SdkServer shutdown | |
| [206.51 DEBUG] (Handle receiveMessage:158) < CANCEL@102.5 | |
| [206.51 INFO] (SDKD log:137) WARNING: Shutting Down.. | |
| [206.52 ERROR] (BRun maybePropagate:241) Suppressing driver-related error | |
| com.couchbase.sdkdclient.context.HarnessException: java.io.IOException: Connection Closed | |
| at com.couchbase.sdkdclient.context.HarnessException.create(HarnessException.java:56) ~[sdkdclient-1.0-SNAPSHOT.jar:na] | |
| at com.couchbase.sdkdclient.scenario.PhasedScenario.run(PhasedScenario.java:115) ~[sdkdclient-1.0-SNAPSHOT.jar:na] | |
| at com.couchbase.sdkdclient.context.RunContext$4.call(RunContext.java:262) ~[sdkdclient-1.0-SNAPSHOT.jar:na] | |
| at com.couchbase.sdkdclient.context.RunContext$4.call(RunContext.java:258) ~[sdkdclient-1.0-SNAPSHOT.jar:na] | |
| at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_25] | |
| at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_25] | |
| at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_25] | |
| at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_25] | |
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_25] | |
| at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_25] | |
| Caused by: java.io.IOException: Connection Closed | |
| at com.couchbase.sdkdclient.handle.Handle.receiveMessage(Handle.java:154) ~[sdkdclient-1.0-SNAPSHOT.jar:na] | |
| at com.couchbase.sdkdclient.workload.Workload.collect(Workload.java:164) ~[sdkdclient-1.0-SNAPSHOT.jar:na] | |
| at com.couchbase.sdkdclient.workload.WorkloadGroup.collect(WorkloadGroup.java:73) ~[sdkdclient-1.0-SNAPSHOT.jar:na] | |
| at com.couchbase.sdkdclient.scenario.PhasedScenario.run(PhasedScenario.java:113) ~[sdkdclient-1.0-SNAPSHOT.jar:na] | |
| ... 8 common frames omitted | |
| [206.52 DEBUG] (Handle sendMessageAsync:183) > CLOSEHANDLE@102.6 | |
| [206.52 DEBUG] (Handle sendMessageAsync:183) > GOODBYE@0.7 | |
| [206.52 INFO] (SDKD log:137) Aug 31, 2015 2:25:23 PM com.couchbase.sdkd.server.ControlServer run | |
| [206.52 DEBUG] (Handle sendMessageAsync:183) > CLOSEHANDLE@100.8 | |
| [206.52 INFO] (SDKD log:137) INFO: ioLoop returned false. Returning.. | |
| [206.52 INFO] (SDKD log:137) Aug 31, 2015 2:25:23 PM com.couchbase.sdkd.server.SdkServer shutdown | |
| [206.52 INFO] (SDKD log:137) WARNING: Shutting Down.. | |
| [206.52 INFO] (SDKD log:137) Aug 31, 2015 2:25:23 PM com.couchbase.sdkd.server.SdkServer shutdown | |
| [206.53 INFO] (SDKD log:137) WARNING: Shutting Down.. | |
| [206.53 INFO] (SDKD log:137) Aug 31, 2015 2:25:23 PM com.couchbase.sdkd.server.ControlServer run | |
| [206.53 INFO] (SDKD log:137) INFO: Cleaned up all children. Now returning for real.. | |
| [206.53 INFO] (HostPortDriver stop:123) SDKD is not yet terminated. Terminating.. | |
| [206.53 INFO] (HostPortDriver terminate:44) Waiting for process termination.. | |
| [206.53 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.read1(BufferedInputStream.java:283) ~[na:1.8.0_25] | |
| at java.io.BufferedInputStream.read(BufferedInputStream.java:345) ~[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] | |
| [206.88 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