Setup
- Version of Fedora
7477d568e3748381939d03e65d183fdd364590 (2016-06-06, 4.5.2-SNAPSHOT)
- Modeshape5
- Fedora configuration details
/etc/default/tomcat7
JAVA_OPTS="-Djava.awt.headless=true" JAVA_OPTS="${JAVA_OPTS} -XX:+DisableExplicitGC" JAVA_OPTS="${JAVA_OPTS} -Xms512m" JAVA_OPTS="${JAVA_OPTS} -Xmx6g" JAVA_OPTS="${JAVA_OPTS} -XX:NewSize=256m" JAVA_OPTS="${JAVA_OPTS} -XX:MaxNewSize=2g" JAVA_OPTS="${JAVA_OPTS} -XX:MetaspaceSize=64m" JAVA_OPTS="${JAVA_OPTS} -XX:MaxMetaspaceSize=2g" JAVA_OPTS="${JAVA_OPTS} -Dfile.encoding=UTF-8" JAVA_OPTS="${JAVA_OPTS} -Xloggc:/var/log/tomcat7/java-gc.log" JAVA_OPTS="${JAVA_OPTS} -XX:+PrintGCDetails" JAVA_OPTS="${JAVA_OPTS} -XX:+PrintGCDateStamps" JAVA_OPTS="${JAVA_OPTS} -Dfcrepo.home=/data/test" JAVA_OPTS="${JAVA_OPTS} -Dfcrepo.mysql.username=root" JAVA_OPTS="${JAVA_OPTS} -Dfcrepo.mysql.password=password" JAVA_OPTS="${JAVA_OPTS} -Dfcrepo.mysql.host=localhost" JAVA_OPTS="${JAVA_OPTS} -Dfcrepo.mysql.port=3306" JAVA_OPTS="${JAVA_OPTS} -Dfcrepo.modeshape.configuration=classpath:/config/jdbc-mysql/repository.json" JAVA_OPTS="${JAVA_OPTS} -agentpath:/home/nruest/yjp-2016.02/bin/linux-x86-64/libyjpagent.so=delay=10000" JAVA_OPTS="${JAVA_OPTS} -Dfcrepo.modeshape.configuration=classpath:/config/jdbc-mysql/repository.json"
- System details (OS, memory, processors, hardware specs or virtualization, JVM, etc)
- Virtual server; 8GiB memory, 2 virutal cpus, fcrepo data is a NFS mount
Ubuntu 14.04.4 LTS
- MySQL (Ver 14.14 Distrib 5.5.49, for debian-linux-gnu (x86_64) using readline 6.3)
- MySQL data directory was on NFS mount
- Initial state of the repository
- empty
- Number of client processes/threads (ideally clients are on a separate machine)
- 1
- JMeter client on separate machine
Test
Remote:
./jmeter -Dfedora_4_server=zeta.library.yorku.ca -Dfedora_4_context=fcrepo/rest -Dfilesize_min=10240 -Dfilesize_max=102400 -Dbinary_threads=1 -n -t /home/nruest/git/fcrepo4-jmeter/fedora.jmx >>| /home/nruest/tmp/yorku-test-3-mysql-summary.log
Results
summary = 1338426 in 294189s = 4.5/s Avg: 213 Min: 4 Max: 18031 Err: 1 (0.00%)
yorku-test-3-mysql-summary.log
WARN 21:44:07.378 (ProxyConnection) HikariPool-0 - Connection com.mysql.jdbc.JDBC4Connection@40e9318d marked as broken because of SQLSTATE(08S01), ErrorCode(0) com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure The last packet successfully received from the server was 9,630 milliseconds ago. The last packet sent successfully to the server was 9,630 milliseconds ago. at sun.reflect.GeneratedConstructorAccessor69.newInstance(Unknown Source) ~[na:na] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_91] at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_91] at com.mysql.jdbc.Util.handleNewInstance(Util.java:404) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:981) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3465) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1962) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52) ~[HikariCP-2.4.3.jar:na] at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java) [HikariCP-2.4.3.jar:na] at org.modeshape.persistence.relational.DefaultStatements.loadIDs(DefaultStatements.java:140) [modeshape-persistence-relational-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.persistence.relational.DefaultStatements.lambda$load$0(DefaultStatements.java:123) [modeshape-persistence-relational-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.persistence.relational.DefaultStatements.runBatchOperation(DefaultStatements.java:216) [modeshape-persistence-relational-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.persistence.relational.DefaultStatements.load(DefaultStatements.java:122) [modeshape-persistence-relational-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.persistence.relational.RelationalDb.lambda$load$13(RelationalDb.java:187) ~[modeshape-persistence-relational-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.persistence.relational.RelationalDb.runWithConnection(RelationalDb.java:353) ~[modeshape-persistence-relational-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.persistence.relational.RelationalDb.load(RelationalDb.java:187) ~[modeshape-persistence-relational-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.jcr.cache.document.LocalDocumentStore.load(LocalDocumentStore.java:82) ~[modeshape-jcr-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.jcr.cache.document.WorkspaceCache.loadFromDocumentStore(WorkspaceCache.java:336) ~[modeshape-jcr-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.jcr.cache.document.WritableSessionCache.lockNodes(WritableSessionCache.java:1565) ~[modeshape-jcr-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.jcr.cache.document.WritableSessionCache.save(WritableSessionCache.java:707) ~[modeshape-jcr-5.0.0.Final.jar:5.0.0.Final] at org.modeshape.jcr.JcrSession.save(JcrSession.java:1162) ~[modeshape-jcr-5.0.0.Final.jar:5.0.0.Final] at org.fcrepo.http.api.FedoraLdp.createObject(FedoraLdp.java:573) ~[fcrepo-http-api-4.5.2-SNAPSHOT.jar:4.5.2-SNAPSHOT] at sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source) ~[na:na] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_91] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_91] at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) ~[jersey-common-2.22.2.jar:na] at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) ~[jersey-common-2.22.2.jar:na] at org.glassfish.jersey.internal.Errors.process(Errors.java:315) ~[jersey-common-2.22.2.jar:na] at org.glassfish.jersey.internal.Errors.process(Errors.java:297) ~[jersey-common-2.22.2.jar:na] at org.glassfish.jersey.internal.Errors.process(Errors.java:267) ~[jersey-common-2.22.2.jar:na] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) ~[jersey-common-2.22.2.jar:na] at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) ~[jersey-server-2.22.2.jar:na] at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) ~[jersey-container-servlet-core-2.22.2.jar:na] at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) ~[jersey-container-servlet-core-2.22.2.jar:na] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) ~[jersey-container-servlet-core-2.22.2.jar:na] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) ~[jersey-container-servlet-core-2.22.2.jar:na] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) ~[jersey-container-servlet-core-2.22.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:98) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408) ~[tomcat-catalina-7.0.52.jar:7.0.52] at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1041) ~[tomcat-coyote-7.0.52.jar:7.0.52] at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607) ~[tomcat-coyote-7.0.52.jar:7.0.52] at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:315) ~[tomcat-coyote-7.0.52.jar:7.0.52] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_91] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_91] at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_91] Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost. at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2957) ~[mysql-connector-java-5.1.38.jar:5.1.38] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375) ~[mysql-connector-java-5.1.38.jar:5.1.38] ... 63 common frames omitted ERROR 21:44:08.228 (RepositoryExceptionMapper) Caught a repository exception: org.modeshape.persistence.relational.RelationalProviderException: java.sql.SQLException: Connection is closed
4 Comments
Andrew Woods
Michael Durbin, do you have any thoughts on what Nick Ruest could do in configuring MySQL for the above error?
Jim Coble
Nick Ruest, Andrew Woods We are seeing a similar error in our current Fedora 4.7.1 testing; namely, first request of the day results in an error like this ...
Subsequent requests succeed. We are trying the "autoReconnect=true" tactic suggested by the error message (no definitive results on that yet) but I'm curious if any other (better) solution has been found.
Thanks.
Andrew Woods
Michael Durbin ^^
Jim Coble
Andrew Woods, Michael Durbin I may have found a solution to this issue. Our initial 4.7.1 setup was using a JNDI datasource for the MySQL database. I have switched that back to putting the database information directly in the repository.json file and, while it's early, it looks like that may have fixed the problem. I'm guessing the problem is not in using a JNDI datasource per se but rather in the way I had configured that datasource. If I am able to figure out something more specific about why the current approach works and the JNDI datasource didn't, I'll let you (and the community) know.