Created
November 24, 2015 02:19
-
-
Save wcpan/a414f8ad28ccf73f8fec to your computer and use it in GitHub Desktop.
error
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
| /Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/bin/java -Dvisualvm.id=180414960240914 -ea -Didea.launcher.port=7536 "-Didea.launcher.bin.path=/Applications/IntelliJ IDEA 15.app/Contents/bin" -Didea.testng.sm_runner -Dfile.encoding=UTF-8 -classpath "/Applications/IntelliJ IDEA 15.app/Contents/lib/idea_rt.jar:/Applications/IntelliJ IDEA 15.app/Contents/plugins/testng/lib/testng-plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/lib/tools.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/jfxswt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/cldrdata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/nashorn.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_25.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Users/wcpan2/git/gondola/containers/jersey2-routing/target/test-classes:/Users/wcpan2/git/gondola/containers/jersey2-routing/target/classes:/Users/wcpan2/.m2/repository/org/apache/httpcomponents/httpclient/4.5.1/httpclient-4.5.1.jar:/Users/wcpan2/.m2/repository/org/apache/httpcomponents/httpcore/4.4.3/httpcore-4.4.3.jar:/Users/wcpan2/.m2/repository/commons-logging/commons-logging/1.2/commons-logging-1.2.jar:/Users/wcpan2/.m2/repository/commons-codec/commons-codec/1.9/commons-codec-1.9.jar:/Users/wcpan2/.m2/repository/org/apache/httpcomponents/httpclient/4.5.1/httpclient-4.5.1-tests.jar:/Users/wcpan2/.m2/repository/commons-io/commons-io/2.4/commons-io-2.4.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/containers/jersey-container-jetty-servlet/2.22/jersey-container-jetty-servlet-2.22.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/containers/jersey-container-servlet/2.22/jersey-container-servlet-2.22.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/containers/jersey-container-servlet-core/2.22/jersey-container-servlet-core-2.22.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/containers/jersey-container-jetty-http/2.22/jersey-container-jetty-http-2.22.jar:/Users/wcpan2/.m2/repository/org/glassfish/hk2/external/javax.inject/2.4.0-b31/javax.inject-2.4.0-b31.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-server/9.1.1.v20140108/jetty-server-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/javax/servlet/javax.servlet-api/3.1.0/javax.servlet-api-3.1.0.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-http/9.1.1.v20140108/jetty-http-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-io/9.1.1.v20140108/jetty-io-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-util/9.1.1.v20140108/jetty-util-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-continuation/9.1.1.v20140108/jetty-continuation-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-webapp/9.1.1.v20140108/jetty-webapp-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-xml/9.1.1.v20140108/jetty-xml-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-servlet/9.1.1.v20140108/jetty-servlet-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/org/eclipse/jetty/jetty-security/9.1.1.v20140108/jetty-security-9.1.1.v20140108.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/core/jersey-common/2.22/jersey-common-2.22.jar:/Users/wcpan2/.m2/repository/javax/annotation/javax.annotation-api/1.2/javax.annotation-api-1.2.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/bundles/repackaged/jersey-guava/2.22/jersey-guava-2.22.jar:/Users/wcpan2/.m2/repository/org/glassfish/hk2/hk2-api/2.4.0-b31/hk2-api-2.4.0-b31.jar:/Users/wcpan2/.m2/repository/org/glassfish/hk2/hk2-utils/2.4.0-b31/hk2-utils-2.4.0-b31.jar:/Users/wcpan2/.m2/repository/org/glassfish/hk2/external/aopalliance-repackaged/2.4.0-b31/aopalliance-repackaged-2.4.0-b31.jar:/Users/wcpan2/.m2/repository/org/glassfish/hk2/hk2-locator/2.4.0-b31/hk2-locator-2.4.0-b31.jar:/Users/wcpan2/.m2/repository/org/glassfish/hk2/osgi-resource-locator/1.0.1/osgi-resource-locator-1.0.1.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/core/jersey-server/2.22/jersey-server-2.22.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/core/jersey-client/2.22/jersey-client-2.22.jar:/Users/wcpan2/.m2/repository/org/glassfish/jersey/media/jersey-media-jaxb/2.22/jersey-media-jaxb-2.22.jar:/Users/wcpan2/.m2/repository/javax/validation/validation-api/1.1.0.Final/validation-api-1.1.0.Final.jar:/Users/wcpan2/.m2/repository/javax/ws/rs/javax.ws.rs-api/2.0.1/javax.ws.rs-api-2.0.1.jar:/Users/wcpan2/.m2/repository/com/jcraft/jsch/0.1.53/jsch-0.1.53.jar:/Users/wcpan2/.m2/repository/com/jcraft/jsch.agentproxy.usocket-jna/0.0.9/jsch.agentproxy.usocket-jna-0.0.9.jar:/Users/wcpan2/.m2/repository/com/jcraft/jsch.agentproxy.core/0.0.9/jsch.agentproxy.core-0.0.9.jar:/Users/wcpan2/.m2/repository/net/java/dev/jna/jna/4.1.0/jna-4.1.0.jar:/Users/wcpan2/.m2/repository/net/java/dev/jna/jna-platform/4.1.0/jna-platform-4.1.0.jar:/Users/wcpan2/.m2/repository/com/jcraft/jsch.agentproxy.sshagent/0.0.9/jsch.agentproxy.sshagent-0.0.9.jar:/Users/wcpan2/.m2/repository/com/jcraft/jsch.agentproxy.connector-factory/0.0.6/jsch.agentproxy.connector-factory-0.0.6.jar:/Users/wcpan2/.m2/repository/com/jcraft/jsch.agentproxy.usocket-nc/0.0.6/jsch.agentproxy.usocket-nc-0.0.6.jar:/Users/wcpan2/.m2/repository/com/jcraft/jsch.agentproxy.pageant/0.0.6/jsch.agentproxy.pageant-0.0.6.jar:/Users/wcpan2/.m2/repository/net/java/dev/jna/platform/3.4.0/platform-3.4.0.jar:/Users/wcpan2/.m2/repository/com/jcraft/jsch.agentproxy.jsch/0.0.7/jsch.agentproxy.jsch-0.0.7.jar:/Users/wcpan2/.m2/repository/com/google/guava/guava/18.0/guava-18.0.jar:/Users/wcpan2/git/gondola/core/target/classes:/Users/wcpan2/.m2/repository/com/typesafe/config/1.2.1/config-1.2.1.jar:/Users/wcpan2/.m2/repository/mysql/mysql-connector-java/5.1.35/mysql-connector-java-5.1.35.jar:/Users/wcpan2/.m2/repository/com/h2database/h2/1.4.187/h2-1.4.187.jar:/Users/wcpan2/.m2/repository/com/zaxxer/HikariCP/2.3.8/HikariCP-2.3.8.jar:/Users/wcpan2/.m2/repository/org/javassist/javassist/3.18.2-GA/javassist-3.18.2-GA.jar:/Users/wcpan2/.m2/repository/org/slf4j/slf4j-api/1.7.10/slf4j-api-1.7.10.jar:/Users/wcpan2/.m2/repository/org/slf4j/slf4j-log4j12/1.7.10/slf4j-log4j12-1.7.10.jar:/Users/wcpan2/.m2/repository/log4j/log4j/1.2.17/log4j-1.2.17.jar:/Users/wcpan2/.m2/repository/org/testng/testng/6.8.21/testng-6.8.21.jar:/Users/wcpan2/.m2/repository/org/beanshell/bsh/2.0b4/bsh-2.0b4.jar:/Users/wcpan2/.m2/repository/com/beust/jcommander/1.27/jcommander-1.27.jar:/Users/wcpan2/.m2/repository/org/mockito/mockito-all/1.10.8/mockito-all-1.10.8.jar:/Applications/IntelliJ IDEA 15.app/Contents/plugins/testng/lib/jcommander.jar" com.intellij.rt.execution.application.AppMain org.testng.RemoteTestNGStarter -port 53373 -usedefaultlisteners false -socket53374 @w@/private/var/folders/sc/wbydt3v52r75rxps4dbfc9940000gt/T/idea_working_dirs_testng0.tmp -temp /private/var/folders/sc/wbydt3v52r75rxps4dbfc9940000gt/T/idea_testng0.tmp | |
| [TestNG] Running: | |
| /Users/wcpan2/Library/Caches/IntelliJIdea15/temp-testng-customsuite.xml | |
| 2015-11-23 18:19:38,672 INFO ------- Gondola start: host5, localhost/127.0.0.1:2185, pid=43016 ------- | |
| 2015-11-23 18:19:38,685 INFO localhost:2185 is not active: Connection refused | |
| 2015-11-23 18:19:38,693 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host5 user=sa | |
| 2015-11-23 18:19:38,882 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:38,920 INFO [host5-85] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:38,923 INFO [host5-85] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:38,924 INFO [host5-85] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:38,925 INFO [host5-85] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:38,930 INFO [host5-85] Creating connection to 86 | |
| 2015-11-23 18:19:38,932 WARN [host5-85] Failed to create socket to 86 (localhost/127.0.0.1:2186): Connection refused | |
| 2015-11-23 18:19:38,932 INFO [host5-85] Will retry creating the socket to 86 (localhost/127.0.0.1:2186) every 1000ms | |
| 2015-11-23 18:19:38,933 INFO [host5-85] Creating connection to 84 | |
| 2015-11-23 18:19:38,934 WARN [host5-85] Failed to create socket to 84 (localhost/127.0.0.1:2184): Connection refused | |
| 2015-11-23 18:19:38,934 INFO [host5-85] Will retry creating the socket to 84 (localhost/127.0.0.1:2184) every 1000ms | |
| 2015-11-23 18:19:38,938 INFO [host5-85] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:38,938 INFO [host5-85] - leader=-1 cterm=3 ci=0 latest=(0,0) votedFor=85 msgPool=0/4 | |
| 2015-11-23 18:19:38,939 INFO [host5-85] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:38,939 INFO [host5-85] - peer=86 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:38,939 INFO [host5-85] - peer=84 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:38,939 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,139 INFO ------- Gondola start: host4, localhost/127.0.0.1:2184, pid=43016 ------- | |
| 2015-11-23 18:19:39,140 INFO localhost:2184 is not active: Connection refused | |
| 2015-11-23 18:19:39,141 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host4 user=sa | |
| 2015-11-23 18:19:39,145 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:39,148 INFO [host4-84] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,148 INFO [host4-84] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:39,148 INFO [host4-84] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:39,149 INFO [host4-84] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,150 INFO [host4-84] Creating connection to 86 | |
| 2015-11-23 18:19:39,151 INFO [host4-84] Creating connection to 85 | |
| 2015-11-23 18:19:39,151 WARN [host4-84] Failed to create socket to 86 (localhost/127.0.0.1:2186): Connection refused | |
| 2015-11-23 18:19:39,151 INFO [host4-84] Will retry creating the socket to 86 (localhost/127.0.0.1:2186) every 1000ms | |
| 2015-11-23 18:19:39,151 INFO [host4-84] Socket created to 85 (localhost/127.0.0.1:2185) | |
| 2015-11-23 18:19:39,151 INFO [host5] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,152 INFO [host4-84] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:39,152 INFO [host4-84] - leader=-1 cterm=3 ci=0 latest=(0,0) votedFor=-1 msgPool=0/4 | |
| 2015-11-23 18:19:39,152 INFO [host4-84] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:39,153 INFO [host4-84] - peer=86 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,153 INFO [host4-84] - peer=85 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,153 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,154 INFO [host5-85] Socket created to 84 (localhost/127.0.0.1:2184) | |
| 2015-11-23 18:19:39,154 INFO [host4] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,155 INFO [host4-84] Socket to 85 is now operational | |
| 2015-11-23 18:19:39,155 INFO [host5-85] Socket to 84 is now operational | |
| 2015-11-23 18:19:39,160 INFO ------- Gondola start: host7, localhost/127.0.0.1:2187, pid=43016 ------- | |
| 2015-11-23 18:19:39,161 INFO localhost:2187 is not active: Connection refused | |
| 2015-11-23 18:19:39,161 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host7 user=sa | |
| 2015-11-23 18:19:39,165 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:39,168 INFO [host7-87] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,168 INFO [host7-87] Becomes FOLLOWER of -1 (primary) | |
| 2015-11-23 18:19:39,168 INFO [host7-87] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:39,169 INFO [host7-87] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,170 INFO [host7-87] Creating connection to 88 | |
| 2015-11-23 18:19:39,170 INFO [host7-87] Creating connection to 89 | |
| 2015-11-23 18:19:39,170 WARN [host7-87] Failed to create socket to 88 (localhost/127.0.0.1:2188): Connection refused | |
| 2015-11-23 18:19:39,170 INFO [host7-87] Will retry creating the socket to 88 (localhost/127.0.0.1:2188) every 1000ms | |
| 2015-11-23 18:19:39,171 WARN [host7-87] Failed to create socket to 89 (localhost/127.0.0.1:2189): Connection refused | |
| 2015-11-23 18:19:39,171 INFO [host7-87] Will retry creating the socket to 89 (localhost/127.0.0.1:2189) every 1000ms | |
| 2015-11-23 18:19:39,171 INFO [host7-87] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:39,172 INFO [host7-87] - leader=-1 cterm=67 ci=0 latest=(0,0) votedFor=88 msgPool=0/4 | |
| 2015-11-23 18:19:39,172 INFO [host7-87] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:39,172 INFO [host7-87] - peer=88 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,172 INFO [host7-87] - peer=89 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,172 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,178 INFO ------- Gondola start: host6, localhost/127.0.0.1:2186, pid=43016 ------- | |
| 2015-11-23 18:19:39,179 INFO localhost:2186 is not active: Connection refused | |
| 2015-11-23 18:19:39,179 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host6 user=sa | |
| 2015-11-23 18:19:39,184 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:39,186 INFO [host6-86] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,186 INFO [host6-86] Becomes FOLLOWER of -1 (primary) | |
| 2015-11-23 18:19:39,186 INFO [host6-86] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:39,187 INFO [host6-86] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,188 INFO [host6-86] Creating connection to 85 | |
| 2015-11-23 18:19:39,188 INFO [host6-86] Socket created to 85 (localhost/127.0.0.1:2185) | |
| 2015-11-23 18:19:39,188 INFO [host6-86] Creating connection to 84 | |
| 2015-11-23 18:19:39,188 INFO [host5] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,189 INFO [host6-86] Socket created to 84 (localhost/127.0.0.1:2184) | |
| 2015-11-23 18:19:39,189 INFO [host4] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,189 INFO [host5-85] Socket to 86 is now operational | |
| 2015-11-23 18:19:39,189 INFO [host6-86] Socket to 85 is now operational | |
| 2015-11-23 18:19:39,190 INFO [host6-86] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:39,190 INFO [host4-84] Socket to 86 is now operational | |
| 2015-11-23 18:19:39,190 INFO [host6-86] Socket to 84 is now operational | |
| 2015-11-23 18:19:39,190 INFO [host6-86] - leader=-1 cterm=3 ci=0 latest=(0,0) votedFor=-1 msgPool=1/5 | |
| 2015-11-23 18:19:39,190 INFO [host6-86] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:39,191 INFO [host6-86] - peer=85 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,191 INFO [host6-86] - peer=84 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,191 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,196 INFO ------- Gondola start: host1, localhost/127.0.0.1:2181, pid=43016 ------- | |
| 2015-11-23 18:19:39,197 INFO localhost:2181 is not active: Connection refused | |
| 2015-11-23 18:19:39,197 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host1 user=sa | |
| 2015-11-23 18:19:39,201 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:39,205 INFO [host1-81] Initializing save index with latest=(70,69) maxGap=10 | |
| 2015-11-23 18:19:39,209 INFO [host1-81] Becomes FOLLOWER of -1 (primary) | |
| 2015-11-23 18:19:39,209 INFO [host1-81] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:39,210 INFO [host1-81] Initializing save index with latest=(70,69) maxGap=0 | |
| 2015-11-23 18:19:39,212 INFO [host1-81] Creating connection to 82 | |
| 2015-11-23 18:19:39,212 INFO [host1-81] Creating connection to 83 | |
| 2015-11-23 18:19:39,213 WARN [host1-81] Failed to create socket to 82 (localhost/127.0.0.1:2182): Connection refused | |
| 2015-11-23 18:19:39,213 INFO [host1-81] Will retry creating the socket to 82 (localhost/127.0.0.1:2182) every 1000ms | |
| 2015-11-23 18:19:39,213 WARN [host1-81] Failed to create socket to 83 (localhost/127.0.0.1:2183): Connection refused | |
| 2015-11-23 18:19:39,213 INFO [host1-81] Will retry creating the socket to 83 (localhost/127.0.0.1:2183) every 1000ms | |
| 2015-11-23 18:19:39,214 INFO [host1-81] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:39,214 INFO [host1-81] - leader=-1 cterm=70 ci=0 latest=(70,69) votedFor=83 msgPool=0/4 | |
| 2015-11-23 18:19:39,214 INFO [host1-81] - storage 0.0/s ti=(70,69) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:39,214 INFO [host1-81] - peer=82 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,214 INFO [host1-81] - peer=83 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,214 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,220 INFO ------- Gondola start: host3, localhost/127.0.0.1:2183, pid=43016 ------- | |
| 2015-11-23 18:19:39,220 INFO localhost:2183 is not active: Connection refused | |
| 2015-11-23 18:19:39,220 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host3 user=sa | |
| 2015-11-23 18:19:39,225 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:39,228 INFO [host3-83] Initializing save index with latest=(70,69) maxGap=10 | |
| 2015-11-23 18:19:39,232 INFO [host3-83] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:39,232 INFO [host3-83] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:39,233 INFO [host3-83] Initializing save index with latest=(70,69) maxGap=0 | |
| 2015-11-23 18:19:39,235 INFO [host3-83] Creating connection to 81 | |
| 2015-11-23 18:19:39,235 INFO [host3-83] Socket created to 81 (localhost/127.0.0.1:2181) | |
| 2015-11-23 18:19:39,235 INFO [host1] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,235 INFO [host3-83] Creating connection to 82 | |
| 2015-11-23 18:19:39,236 INFO [host1-81] Socket to 83 is now operational | |
| 2015-11-23 18:19:39,236 INFO [host3-83] Socket to 81 is now operational | |
| 2015-11-23 18:19:39,236 WARN [host3-83] Failed to create socket to 82 (localhost/127.0.0.1:2182): Connection refused | |
| 2015-11-23 18:19:39,236 INFO [host3-83] Will retry creating the socket to 82 (localhost/127.0.0.1:2182) every 1000ms | |
| 2015-11-23 18:19:39,237 INFO [host3-83] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:39,237 INFO [host3-83] - leader=-1 cterm=70 ci=0 latest=(70,69) votedFor=83 msgPool=1/5 | |
| 2015-11-23 18:19:39,237 INFO [host3-83] - storage 0.0/s ti=(70,69) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:39,237 INFO [host3-83] - peer=81 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,237 INFO [host3-83] - peer=82 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,238 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,243 INFO ------- Gondola start: host2, localhost/127.0.0.1:2182, pid=43016 ------- | |
| 2015-11-23 18:19:39,244 INFO localhost:2182 is not active: Connection refused | |
| 2015-11-23 18:19:39,244 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host2 user=sa | |
| 2015-11-23 18:19:39,248 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:39,251 INFO [host2-82] Initializing save index with latest=(70,69) maxGap=10 | |
| 2015-11-23 18:19:39,255 INFO [host2-82] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:39,255 INFO [host2-82] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:39,256 INFO [host2-82] Initializing save index with latest=(70,69) maxGap=0 | |
| 2015-11-23 18:19:39,257 INFO [host2-82] Creating connection to 81 | |
| 2015-11-23 18:19:39,258 INFO [host2-82] Creating connection to 83 | |
| 2015-11-23 18:19:39,258 INFO [host2-82] Socket created to 81 (localhost/127.0.0.1:2181) | |
| 2015-11-23 18:19:39,258 INFO [host1] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,258 INFO [host2-82] Socket created to 83 (localhost/127.0.0.1:2183) | |
| 2015-11-23 18:19:39,259 INFO [host3] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,259 INFO [host1-81] Socket to 82 is now operational | |
| 2015-11-23 18:19:39,259 INFO [host2-82] Socket to 81 is now operational | |
| 2015-11-23 18:19:39,259 INFO [host2-82] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:39,259 INFO [host2-82] - leader=-1 cterm=70 ci=0 latest=(70,69) votedFor=83 msgPool=1/5 | |
| 2015-11-23 18:19:39,260 INFO [host2-82] - storage 0.0/s ti=(70,69) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:39,260 INFO [host3-83] Socket created to 82 (localhost/127.0.0.1:2182) | |
| 2015-11-23 18:19:39,260 INFO [host2-82] - peer=81 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,260 INFO [host2] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,260 INFO [host2-82] - peer=83 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,260 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,261 INFO [host2-82] Socket to 83 is now operational | |
| 2015-11-23 18:19:39,261 INFO [host3-83] Socket to 82 is now operational | |
| 2015-11-23 18:19:39,267 INFO ------- Gondola start: host9, localhost/127.0.0.1:2189, pid=43016 ------- | |
| 2015-11-23 18:19:39,268 INFO localhost:2189 is not active: Connection refused | |
| 2015-11-23 18:19:39,268 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host9 user=sa | |
| 2015-11-23 18:19:39,272 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:39,274 INFO [host9-89] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,275 INFO [host9-89] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:39,275 INFO [host9-89] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:39,276 INFO [host9-89] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,277 INFO [host9-89] Creating connection to 87 | |
| 2015-11-23 18:19:39,285 INFO [host9-89] Creating connection to 88 | |
| 2015-11-23 18:19:39,285 INFO [host9-89] Socket created to 87 (localhost/127.0.0.1:2187) | |
| 2015-11-23 18:19:39,285 INFO [host7] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,286 WARN [host9-89] Failed to create socket to 88 (localhost/127.0.0.1:2188): Connection refused | |
| 2015-11-23 18:19:39,286 INFO [host9-89] Will retry creating the socket to 88 (localhost/127.0.0.1:2188) every 1000ms | |
| 2015-11-23 18:19:39,286 INFO [host7-87] Socket to 89 is now operational | |
| 2015-11-23 18:19:39,286 INFO [host9-89] Socket to 87 is now operational | |
| 2015-11-23 18:19:39,287 INFO [host9-89] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:39,287 INFO [host9-89] - leader=-1 cterm=67 ci=0 latest=(0,0) votedFor=88 msgPool=1/5 | |
| 2015-11-23 18:19:39,287 INFO [host9-89] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:39,288 INFO [host9-89] - peer=87 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,288 INFO [host9-89] - peer=88 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,288 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,294 INFO ------- Gondola start: host8, localhost/127.0.0.1:2188, pid=43016 ------- | |
| 2015-11-23 18:19:39,295 INFO localhost:2188 is not active: Connection refused | |
| 2015-11-23 18:19:39,295 INFO Initializing H2DB storage. maxCommandSize=1000 url=jdbc:h2:/tmp/gondola-db-host8 user=sa | |
| 2015-11-23 18:19:39,299 INFO H2DB autoCommit=true | |
| 2015-11-23 18:19:39,301 INFO [host8-88] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,301 INFO [host8-88] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:39,301 INFO [host8-88] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:39,302 INFO [host8-88] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:39,303 INFO [host8-88] Creating connection to 87 | |
| 2015-11-23 18:19:39,303 INFO [host8-88] Socket created to 87 (localhost/127.0.0.1:2187) | |
| 2015-11-23 18:19:39,303 INFO [host7] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,303 INFO [host8-88] Creating connection to 89 | |
| 2015-11-23 18:19:39,304 INFO [host8-88] Socket created to 89 (localhost/127.0.0.1:2189) | |
| 2015-11-23 18:19:39,304 INFO [host9] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,304 INFO [host7-87] Socket to 88 is now operational | |
| 2015-11-23 18:19:39,304 INFO [host8-88] Socket to 87 is now operational | |
| 2015-11-23 18:19:39,305 INFO [host8-88] FOLLOWER pid=43016 wait=0ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:39,305 INFO [host8-88] - leader=-1 cterm=67 ci=0 latest=(0,0) votedFor=88 msgPool=1/5 | |
| 2015-11-23 18:19:39,305 INFO [host8-88] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:39,305 INFO [host8-88] - peer=87 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,305 INFO [host8] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:39,305 INFO [host9-89] Socket created to 88 (localhost/127.0.0.1:2188) | |
| 2015-11-23 18:19:39,306 INFO [host8-88] - peer=89 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:39,306 INFO b1=NaN, b2=NaN, b3=NaN, b4=NaN b5=NaN 0.000ms/loop | |
| 2015-11-23 18:19:39,306 INFO [host8-88] Socket to 89 is now operational | |
| 2015-11-23 18:19:39,306 INFO [host9-89] Socket to 88 is now operational | |
| 2015-11-23 18:19:39,936 INFO [host5-85] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:39,936 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:40,152 INFO [host4-84] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:40,152 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:40,175 INFO [host7-87] Socket created to 89 (localhost/127.0.0.1:2189) | |
| 2015-11-23 18:19:40,175 INFO [host9] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:40,175 INFO [host8] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:40,175 INFO [host7-87] Socket created to 88 (localhost/127.0.0.1:2188) | |
| 2015-11-23 18:19:40,217 INFO [host3] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:40,217 INFO [host1-81] Socket created to 82 (localhost/127.0.0.1:2182) | |
| 2015-11-23 18:19:40,217 INFO [host2] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:40,217 INFO [host1-81] Socket created to 83 (localhost/127.0.0.1:2183) | |
| 2015-11-23 18:19:40,931 INFO [host5-85] No heartbeat from -1 in 2005ms (timeout=2000ms) | |
| 2015-11-23 18:19:40,931 INFO [host5-85] Becomes CANDIDATE | |
| 2015-11-23 18:19:40,931 INFO [host5-85] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:40,932 INFO [host5-85] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,151 INFO [host4-84] No heartbeat from -1 in 2002ms (timeout=2000ms) | |
| 2015-11-23 18:19:41,151 INFO [host4-84] Becomes CANDIDATE | |
| 2015-11-23 18:19:41,151 INFO [host4-84] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,152 INFO [host4-84] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,156 INFO [host5-85] Has majority of pre-votes (2). Incrementing currentTerm to 4 and sending out request vote | |
| 2015-11-23 18:19:41,157 INFO [host4-84] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:41,157 INFO [host6-86] Voting for 85 in term 4 | |
| 2015-11-23 18:19:41,157 INFO [host4-84] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,158 INFO [host4-84] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,158 INFO [host4-84] Became a follower because term 4 from 85 is > currentTerm 3 | |
| 2015-11-23 18:19:41,158 INFO [host4-84] Voting for 85 in term 4 | |
| 2015-11-23 18:19:41,159 INFO [host5-85] Becomes LEADER for term 4 | |
| 2015-11-23 18:19:41,159 INFO [host5-85] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,159 INFO [host5-85] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,160 ERROR | |
| java.lang.NullPointerException | |
| at java.util.concurrent.ConcurrentHashMap.putVal(ConcurrentHashMap.java:1011) | |
| at java.util.concurrent.ConcurrentHashMap.put(ConcurrentHashMap.java:1006) | |
| at com.yahoo.gondola.container.AdminClientIT.lambda$setUp$1(AdminClientIT.java:80) | |
| at com.yahoo.gondola.container.AdminClientIT$$Lambda$3/932285561.accept(Unknown Source) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier.lambda$run$2(Gondola.java:282) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier$$Lambda$37/2012878801.accept(Unknown Source) | |
| at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:890) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier.run(Gondola.java:282) | |
| 2015-11-23 18:19:41,174 INFO [host7-87] No heartbeat from -1 in 2005ms (timeout=2000ms) | |
| 2015-11-23 18:19:41,174 INFO [host7-87] Becomes CANDIDATE (primary) | |
| 2015-11-23 18:19:41,174 INFO [host7-87] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,175 INFO [host7-87] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,189 INFO [host6-86] No heartbeat from -1 in 2002ms (timeout=2000ms) | |
| 2015-11-23 18:19:41,190 INFO [host6-86] Becomes CANDIDATE (primary) | |
| 2015-11-23 18:19:41,190 INFO [host6-86] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,191 INFO [host6-86] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,211 INFO [host1-81] No heartbeat from -1 in 2000ms (timeout=2000ms) | |
| 2015-11-23 18:19:41,211 INFO [host1-81] Becomes CANDIDATE (primary) | |
| 2015-11-23 18:19:41,211 INFO [host1-81] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,213 INFO [host1-81] Initializing save index with latest=(70,69) maxGap=0 | |
| 2015-11-23 18:19:41,235 INFO [host3-83] No heartbeat from -1 in 2001ms (timeout=2000ms) | |
| 2015-11-23 18:19:41,235 INFO [host3-83] Becomes CANDIDATE | |
| 2015-11-23 18:19:41,235 INFO [host3-83] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,237 INFO [host3-83] Initializing save index with latest=(70,69) maxGap=0 | |
| 2015-11-23 18:19:41,242 INFO [host1-81] Has majority of pre-votes (2). Incrementing currentTerm to 71 and sending out request vote | |
| 2015-11-23 18:19:41,243 INFO [host2-82] Voting for 81 in term 71 | |
| 2015-11-23 18:19:41,243 INFO [host3-83] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:41,243 INFO [host3-83] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,243 INFO [host1-81] Becomes LEADER for term 71 (primary) | |
| 2015-11-23 18:19:41,244 INFO [host1-81] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,244 INFO [host3-83] Initializing save index with latest=(70,69) maxGap=0 | |
| 2015-11-23 18:19:41,244 INFO [host1-81] Initializing save index with latest=(70,69) maxGap=0 | |
| 2015-11-23 18:19:41,245 INFO [host3-83] Became a follower because term 71 from 81 is > currentTerm 70 | |
| 2015-11-23 18:19:41,245 INFO [host3-83] Voting for 81 in term 71 | |
| 2015-11-23 18:19:41,245 ERROR | |
| java.lang.NullPointerException | |
| at java.util.concurrent.ConcurrentHashMap.putVal(ConcurrentHashMap.java:1011) | |
| at java.util.concurrent.ConcurrentHashMap.put(ConcurrentHashMap.java:1006) | |
| at com.yahoo.gondola.container.AdminClientIT.lambda$setUp$1(AdminClientIT.java:80) | |
| at com.yahoo.gondola.container.AdminClientIT$$Lambda$3/932285561.accept(Unknown Source) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier.lambda$run$2(Gondola.java:282) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier$$Lambda$37/2012878801.accept(Unknown Source) | |
| at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:890) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier.run(Gondola.java:282) | |
| 2015-11-23 18:19:41,280 INFO [host9-89] No heartbeat from -1 in 2004ms (timeout=2000ms) | |
| 2015-11-23 18:19:41,280 INFO [host9-89] Becomes CANDIDATE | |
| 2015-11-23 18:19:41,280 INFO [host9-89] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,281 INFO [host9-89] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,306 INFO [host8-88] No heartbeat from -1 in 2004ms (timeout=2000ms) | |
| 2015-11-23 18:19:41,306 INFO [host8-88] Becomes CANDIDATE | |
| 2015-11-23 18:19:41,306 INFO [host8-88] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,307 INFO [host8-88] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,391 INFO [host9-89] Has majority of pre-votes (2). Incrementing currentTerm to 68 and sending out request vote | |
| 2015-11-23 18:19:41,392 INFO [host7-87] Becomes FOLLOWER of -1 (primary) | |
| 2015-11-23 18:19:41,392 INFO [host8-88] Becomes FOLLOWER of -1 | |
| 2015-11-23 18:19:41,392 INFO [host7-87] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,392 INFO [host8-88] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,393 INFO [host7-87] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,393 INFO [host8-88] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,393 INFO [host7-87] Became a follower because term 68 from 89 is > currentTerm 67 | |
| 2015-11-23 18:19:41,393 INFO [host7-87] Voting for 89 in term 68 | |
| 2015-11-23 18:19:41,393 INFO [host8-88] Became a follower because term 68 from 89 is > currentTerm 67 | |
| 2015-11-23 18:19:41,393 INFO [host8-88] Voting for 89 in term 68 | |
| 2015-11-23 18:19:41,394 INFO [host9-89] Becomes LEADER for term 68 | |
| 2015-11-23 18:19:41,394 INFO [host9-89] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,394 INFO [host9-89] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,395 ERROR | |
| java.lang.NullPointerException | |
| at java.util.concurrent.ConcurrentHashMap.putVal(ConcurrentHashMap.java:1011) | |
| at java.util.concurrent.ConcurrentHashMap.put(ConcurrentHashMap.java:1006) | |
| at com.yahoo.gondola.container.AdminClientIT.lambda$setUp$1(AdminClientIT.java:80) | |
| at com.yahoo.gondola.container.AdminClientIT$$Lambda$3/932285561.accept(Unknown Source) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier.lambda$run$2(Gondola.java:282) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier$$Lambda$37/2012878801.accept(Unknown Source) | |
| at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:890) | |
| at com.yahoo.gondola.Gondola$RoleChangeNotifier.run(Gondola.java:282) | |
| 2015-11-23 18:19:41,399 INFO Executing assign buckets=[0‥10] from shard1 to shard2 | |
| 2015-11-23 18:19:41,399 INFO Initializing slaves on shard2 ... | |
| 2015-11-23 18:19:41,400 INFO [host6] shardId=shard2 follows shardId=shard1 as slave | |
| 2015-11-23 18:19:41,401 WARN [host5-85] recv(86): end-of-file | |
| 2015-11-23 18:19:41,401 INFO [host5-85] Reconnecting socket Socket[addr=/127.0.0.1,port=53393,localport=2185] to 86 | |
| 2015-11-23 18:19:41,401 WARN [host4-84] recv(86): end-of-file | |
| 2015-11-23 18:19:41,401 INFO [host4-84] Reconnecting socket Socket[addr=/127.0.0.1,port=53394,localport=2184] to 86 | |
| 2015-11-23 18:19:41,402 INFO [host5-85] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:41,402 INFO [host6-86] Becomes FOLLOWER of 81 (primary) | |
| 2015-11-23 18:19:41,402 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,402 INFO [host6-86] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,402 INFO [host4-84] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:41,402 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,402 INFO [host6-86] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,403 INFO [host6-86] Creating connection to 81 | |
| 2015-11-23 18:19:41,404 INFO [host1] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,404 INFO [host6-86] Socket created to 81 (localhost/127.0.0.1:2181) | |
| 2015-11-23 18:19:41,404 INFO [host1-81] Creating connection to 86 | |
| 2015-11-23 18:19:41,405 INFO [host1-81] Socket to 86 is now operational | |
| 2015-11-23 18:19:41,405 INFO [host1-81] Slave request from 86 accepted | |
| 2015-11-23 18:19:41,405 INFO [host1-81] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:41,405 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,405 WARN [host1-81] Failed to create socket to 86 (localhost/127.0.0.1:2186): null | |
| java.lang.AssertionError | |
| at com.yahoo.gondola.impl.SocketNetwork$Hello.makeCall(SocketNetwork.java:366) | |
| at com.yahoo.gondola.impl.SocketChannel$SocketCreator.run(SocketChannel.java:356) | |
| 2015-11-23 18:19:41,405 INFO [host1-81] Will retry creating the socket to 86 (localhost/127.0.0.1:2186) every 1000ms | |
| 2015-11-23 18:19:41,405 WARN End-of-file | |
| 2015-11-23 18:19:41,406 INFO [host5] shardId=shard2 follows shardId=shard1 as slave | |
| 2015-11-23 18:19:41,407 WARN [host4-84] recv(85): end-of-file | |
| 2015-11-23 18:19:41,407 INFO [host4-84] Reconnecting socket Socket[addr=/127.0.0.1,port=53384,localport=2184] to 85 | |
| 2015-11-23 18:19:41,407 INFO [host5-85] Becomes FOLLOWER of 81 | |
| 2015-11-23 18:19:41,407 INFO [host5-85] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,407 INFO [host4-84] Socket created to 85 (localhost/127.0.0.1:2185) | |
| 2015-11-23 18:19:41,407 INFO [host5] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,408 INFO [host5-85] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,408 INFO [host5-85] Leader has not heard from enough followers | |
| 2015-11-23 18:19:41,408 INFO [host5-85] Becomes CANDIDATE | |
| 2015-11-23 18:19:41,408 INFO [host5-85] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,408 INFO [host5-85] Creating connection to 81 | |
| 2015-11-23 18:19:41,408 INFO [host5-85] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,409 INFO [host5-85] Socket created to 81 (localhost/127.0.0.1:2181) | |
| 2015-11-23 18:19:41,409 INFO [host1] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,409 INFO [host4] shardId=shard2 follows shardId=shard1 as slave | |
| 2015-11-23 18:19:41,409 INFO [host4-84] Becomes FOLLOWER of 81 | |
| 2015-11-23 18:19:41,409 INFO [host4-84] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:41,409 INFO [host1-81] Creating connection to 85 | |
| 2015-11-23 18:19:41,409 INFO [host1-81] Socket to 85 is now operational | |
| 2015-11-23 18:19:41,409 INFO [host1-81] Slave request from 85 accepted | |
| 2015-11-23 18:19:41,410 INFO [host4-84] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:41,410 INFO [host1-81] Socket created to 85 (localhost/127.0.0.1:2185) | |
| 2015-11-23 18:19:41,410 INFO [host5] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,410 WARN [host1-81] Failed to create socket to 85 (localhost/127.0.0.1:2185): null | |
| java.lang.AssertionError | |
| at com.yahoo.gondola.impl.SocketNetwork$Hello.makeCall(SocketNetwork.java:366) | |
| at com.yahoo.gondola.impl.SocketChannel$SocketCreator.run(SocketChannel.java:356) | |
| 2015-11-23 18:19:41,410 INFO [host1-81] Will retry creating the socket to 85 (localhost/127.0.0.1:2185) every 1000ms | |
| 2015-11-23 18:19:41,410 INFO [host4-84] Creating connection to 81 | |
| 2015-11-23 18:19:41,410 WARN Broken pipe | |
| 2015-11-23 18:19:41,411 INFO All nodes in shard2 are in slave mode, waiting for slave logs approaching to leader's log position. | |
| 2015-11-23 18:19:41,411 INFO [host4-84] Socket created to 81 (localhost/127.0.0.1:2181) | |
| 2015-11-23 18:19:41,411 INFO [host1] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,411 INFO Waiting for slaves logs approaching... | |
| 2015-11-23 18:19:41,411 INFO [host1-81] Creating connection to 84 | |
| 2015-11-23 18:19:41,411 INFO [host1-81] Socket to 84 is now operational | |
| 2015-11-23 18:19:41,411 INFO [host1-81] Slave request from 84 accepted | |
| 2015-11-23 18:19:41,412 INFO [host1-81] Socket created to 84 (localhost/127.0.0.1:2184) | |
| 2015-11-23 18:19:41,412 INFO [host4] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:41,412 WARN [host1-81] Failed to create socket to 84 (localhost/127.0.0.1:2184): null | |
| java.lang.AssertionError | |
| at com.yahoo.gondola.impl.SocketNetwork$Hello.makeCall(SocketNetwork.java:366) | |
| at com.yahoo.gondola.impl.SocketChannel$SocketCreator.run(SocketChannel.java:356) | |
| 2015-11-23 18:19:41,412 INFO [host1-81] Will retry creating the socket to 84 (localhost/127.0.0.1:2184) every 1000ms | |
| 2015-11-23 18:19:41,412 WARN Connection reset | |
| 2015-11-23 18:19:41,419 INFO [host6] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:41,419 INFO [host4] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:41,419 INFO [host5] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:42,409 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:42,409 INFO [host1-81] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:42,410 WARN End-of-file | |
| 2015-11-23 18:19:42,413 INFO [host1-81] Socket created to 85 (localhost/127.0.0.1:2185) | |
| 2015-11-23 18:19:42,413 INFO [host5] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:42,413 INFO [host1-81] Socket created to 84 (localhost/127.0.0.1:2184) | |
| 2015-11-23 18:19:42,413 INFO [host4] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:42,413 WARN End-of-file | |
| 2015-11-23 18:19:42,414 WARN Connection reset | |
| 2015-11-23 18:19:42,424 INFO [host5] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:42,424 INFO [host6] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:42,424 INFO [host4] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:43,407 INFO [host6-86] No heartbeat from 81 in 2004ms (timeout=2000ms) | |
| 2015-11-23 18:19:43,408 INFO [host6-86] Becomes CANDIDATE (primary) | |
| 2015-11-23 18:19:43,408 INFO [host6-86] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:43,408 INFO [host6-86] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:43,414 INFO [host4-84] No heartbeat from 81 in 2004ms (timeout=2000ms) | |
| 2015-11-23 18:19:43,414 INFO [host4-84] Becomes CANDIDATE | |
| 2015-11-23 18:19:43,414 INFO [host1-81] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:43,414 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:43,415 INFO [host4-84] Settling storage. workQ=0 busy=0 maxGap=0 | |
| 2015-11-23 18:19:43,415 WARN End-of-file | |
| 2015-11-23 18:19:43,416 INFO [host4-84] Initializing save index with latest=(0,0) maxGap=0 | |
| 2015-11-23 18:19:43,417 INFO [host1-81] Socket created to 85 (localhost/127.0.0.1:2185) | |
| 2015-11-23 18:19:43,417 INFO [host5] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:43,417 INFO [host4] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:43,417 INFO [host1-81] Socket created to 84 (localhost/127.0.0.1:2184) | |
| 2015-11-23 18:19:43,418 WARN Broken pipe | |
| 2015-11-23 18:19:43,419 WARN Broken pipe | |
| 2015-11-23 18:19:43,429 INFO [host6] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:43,430 INFO [host4] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:43,429 INFO [host5] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:44,122 INFO [host5-85] CANDIDATE pid=43016 wait=221ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:44,122 INFO [host5-85] - leader=-1 cterm=1 ci=0 latest=(0,0) votedFor=85 msgPool=2/6 | |
| 2015-11-23 18:19:44,122 INFO [host5-85] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:44,124 INFO [host5-85] - peer=81 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,124 INFO b1=0.0, b2=0.1, b3=0.1, b4=99.7 b5=99.7 172.794ms/loop | |
| 2015-11-23 18:19:44,174 INFO [host7-87] FOLLOWER pid=43016 wait=250ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:44,174 INFO [host7-87] - leader=89 cterm=68 ci=0 latest=(0,0) votedFor=89 msgPool=1/6 | |
| 2015-11-23 18:19:44,174 INFO [host7-87] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:44,174 INFO [host7-87] - peer=88 U in=0.0/s|0.0B/s out=0|0.4/s|7.2B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,174 INFO [host7-87] - peer=89 U in=2.6/s|66.6B/s out=0|2.8/s|41.6B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,174 INFO b1=0.0, b2=0.0, b3=0.1, b4=99.9 b5=99.9 156.322ms/loop | |
| 2015-11-23 18:19:44,249 INFO [host6-86] CANDIDATE pid=43016 wait=222ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:44,249 INFO [host6-86] - leader=-1 cterm=1 ci=0 latest=(0,0) votedFor=85 msgPool=2/6 | |
| 2015-11-23 18:19:44,249 INFO [host6-86] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:44,249 INFO [host6-86] - peer=81 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,249 INFO b1=0.0, b2=0.1, b3=0.0, b4=99.9 b5=99.9 194.548ms/loop | |
| 2015-11-23 18:19:44,259 INFO [host4-84] CANDIDATE pid=43016 wait=123ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:44,259 INFO [host4-84] - leader=-1 cterm=1 ci=0 latest=(0,0) votedFor=85 msgPool=1/5 | |
| 2015-11-23 18:19:44,259 INFO [host4-84] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:44,259 INFO [host4-84] - peer=81 D in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,259 INFO b1=0.0, b2=0.1, b3=0.0, b4=99.8 b5=99.8 196.404ms/loop | |
| 2015-11-23 18:19:44,289 INFO [host1-81] LEADER pid=43016 wait=250ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/4.577ms | |
| 2015-11-23 18:19:44,289 INFO [host3-83] FOLLOWER pid=43016 wait=250ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/2.498ms | |
| 2015-11-23 18:19:44,289 INFO [host2-82] FOLLOWER pid=43016 wait=250ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/2.499ms | |
| 2015-11-23 18:19:44,290 INFO [host1-81] - leader=81 cterm=71 ci=70 latest=(71,70) votedFor=81 msgPool=1/11 | |
| 2015-11-23 18:19:44,290 INFO [host3-83] - leader=81 cterm=71 ci=70 latest=(71,70) votedFor=81 msgPool=2/6 | |
| 2015-11-23 18:19:44,290 INFO [host2-82] - leader=81 cterm=71 ci=70 latest=(71,70) votedFor=81 msgPool=2/6 | |
| 2015-11-23 18:19:44,290 INFO [host1-81] - storage 0.0/s ti=(71,70) saveQ=0 gap=10 done=0 | |
| 2015-11-23 18:19:44,290 INFO [host2-82] - storage 0.0/s ti=(71,70) saveQ=0 gap=10 done=0 | |
| 2015-11-23 18:19:44,290 INFO [host3-83] - storage 0.0/s ti=(71,70) saveQ=0 gap=10 done=0 | |
| 2015-11-23 18:19:44,290 INFO [host2-82] - peer=81 U in=2.8/s|71.6B/s out=0|2.8/s|41.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,290 INFO [host1-81] - peer=82 U in=2.8/s|40.6B/s out=0|2.8/s|70.9B/s ni=71 mi=70 vf=(-1,-1) lat=2.782ms | |
| 2015-11-23 18:19:44,290 INFO [host3-83] - peer=81 U in=2.8/s|71.2B/s out=0|3.0/s|42.9B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,290 INFO [host2-82] - peer=83 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,290 INFO [host3-83] - peer=82 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,290 INFO [host1-81] - peer=83 U in=3.0/s|42.8B/s out=0|2.8/s|70.9B/s ni=71 mi=70 vf=(-1,-1) lat=2.763ms | |
| 2015-11-23 18:19:44,290 INFO b1=0.0, b2=0.1, b3=0.1, b4=99.8 b5=99.8 144.353ms/loop | |
| 2015-11-23 18:19:44,290 INFO b1=0.0, b2=0.0, b3=0.0, b4=99.9 b5=99.9 147.935ms/loop | |
| 2015-11-23 18:19:44,291 INFO [host1-81] - slave=86 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,291 INFO [host1-81] - slave=85 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,291 INFO [host1-81] - slave=84 U in=0.0/s|0.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,291 INFO b1=0.0, b2=0.1, b3=0.0, b4=99.8 b5=99.8 203.021ms/loop | |
| 2015-11-23 18:19:44,416 INFO [host1-81] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:44,416 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:44,417 WARN End-of-file | |
| 2015-11-23 18:19:44,421 INFO [host1-81] Socket created to 85 (localhost/127.0.0.1:2185) | |
| 2015-11-23 18:19:44,421 INFO [host5] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:44,421 INFO [host1-81] Socket created to 84 (localhost/127.0.0.1:2184) | |
| 2015-11-23 18:19:44,421 INFO [host4] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:44,422 WARN End-of-file | |
| 2015-11-23 18:19:44,422 WARN End-of-file | |
| 2015-11-23 18:19:44,427 INFO [host9-89] LEADER pid=43016 wait=250ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:44,427 INFO [host8-88] FOLLOWER pid=43016 wait=250ms cmdQ=0 waitQ=0 in=0|0.0/s out=0.0/s lat=NaNms/NaNms | |
| 2015-11-23 18:19:44,427 INFO [host9-89] - leader=89 cterm=68 ci=0 latest=(0,0) votedFor=89 msgPool=3/7 | |
| 2015-11-23 18:19:44,427 INFO [host8-88] - leader=89 cterm=68 ci=0 latest=(0,0) votedFor=89 msgPool=2/6 | |
| 2015-11-23 18:19:44,427 INFO [host8-88] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:44,427 INFO [host9-89] - storage 0.0/s ti=(0,0) saveQ=0 gap=0 done=0 | |
| 2015-11-23 18:19:44,427 INFO [host8-88] - peer=87 U in=0.4/s|7.0B/s out=0|0.0/s|0.0B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,427 INFO [host9-89] - peer=87 U in=2.9/s|43.4B/s out=0|2.5/s|64.8B/s ni=1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,427 INFO [host8-88] - peer=89 U in=2.5/s|65.0B/s out=0|2.5/s|36.5B/s ni=-1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,427 INFO [host9-89] - peer=88 U in=2.5/s|36.4B/s out=0|2.5/s|64.8B/s ni=1 mi=0 vf=(-1,-1) lat=NaNms | |
| 2015-11-23 18:19:44,427 INFO b1=0.0, b2=0.0, b3=0.1, b4=99.9 b5=99.9 150.657ms/loop | |
| 2015-11-23 18:19:44,428 INFO b1=0.0, b2=0.1, b3=0.0, b4=99.9 b5=99.9 205.595ms/loop | |
| 2015-11-23 18:19:44,432 INFO [host4] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:44,432 INFO [host6] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:44,432 INFO [host5] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:45,422 INFO [host1-81] Socket created to 86 (localhost/127.0.0.1:2186) | |
| 2015-11-23 18:19:45,422 INFO [host6] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:45,423 WARN End-of-file | |
| 2015-11-23 18:19:45,423 INFO [host1-81] Socket created to 84 (localhost/127.0.0.1:2184) | |
| 2015-11-23 18:19:45,423 INFO [host1-81] Socket created to 85 (localhost/127.0.0.1:2185) | |
| 2015-11-23 18:19:45,424 INFO [host4] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:45,424 INFO [host5] Socket accept from /127.0.0.1 | |
| 2015-11-23 18:19:45,425 WARN End-of-file | |
| 2015-11-23 18:19:45,425 WARN End-of-file | |
| 2015-11-23 18:19:45,434 INFO [host6] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:45,434 INFO [host4] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| 2015-11-23 18:19:45,437 INFO [host5] shard2 Log status=DOWN, currentDiff=0, targetDiff=1000 | |
| Process finished with exit code 130 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment