ChemAxon Forum Archive » Storage & search: JChem Base and JChem Oracle Cartridge

Maximum number of searches and read timed out messages

User 104a68add6

28-03-2005 17:41:50

When executing a simple cartridge query with jc_contains, I get an exception stating that I have reached my maximum number of allowed searches per minute after 3 searches. We purchased an upgrade to 8 searches per minute. I asked tech support if there was anything I needed to do to reflect our upgraded license status(a few months back) and was told I needed to do nothing. Here is the message we get after 3 quick searches (I run the exact same command each time):





SQL> select ct_number from structure where jc_contains(cd_smiles, 'C1C2(C1)CCC2') =1;


select ct_number from structure where jc_contains(cd_smiles, 'C1C2(C1)CCC2') =1


*


ERROR at line 1:


ORA-29902: error in executing ODCIIndexStart() routine


ORA-29532: Java call terminated by uncaught Java exception:


java.lang.Exception: The following exception has been thrown by the servlet:


Exception: Maximum number of searches allowed per minute is exceeded. Please


try it later.


ORA-06512: at "JCHEM.JCHEM_CORE_PKG", line 0


ORA-06512: at "JCHEM.JC_IDXTYPE_IM", line 158


ORA-06512: at line 1





The next problem is that when I wait until later (even several to fifteen minutes) in the same session, I never get results again. I only get this new exception:





ERROR at line 1:


ORA-29902: error in executing ODCIIndexStart() routine


ORA-29532: Java call terminated by uncaught Java exception:


java.lang.Exception: The following exception has been thrown by the servlet:


Exception: Read timed out


ORA-06512: at "JCHEM.JCHEM_CORE_PKG", line 0


ORA-06512: at "JCHEM.JC_IDXTYPE_IM", line 158


ORA-06512: at line 1





If I logout of sql*Plus and login again, I can do 3 more queries, and then the same errors repeat themselves.





I understand this could be two separate issues, but they appeared together, and I cannot separate them til the license issue is straightened out....so I am presenting them as one big mess :-)





Thanks for any help you can provide,





Julie

ChemAxon aa7c50abf8

29-03-2005 10:09:56

Each JChem Cartridge user has to enter the license keys as described in http://www.jchem.com/doc/admin/index.html#lickey . The JChem Streams application in Tomcat has to be reloaded (either by using the "Tomcat Web Application Manager" interface or by simply restarting Tomcat) for the new license information to take effect.





I have not been able to reproduce the "Read timeout" problem. (I have been trying on Oracle 10g so far. I am going to try it on 9i as well.)





PS:


In case you want to handle license upgrades in one batch for all cartridge users, I offer you the following unofficial way to do it. (The official way is described at the above URL). Iterate on the following SQL statements for all JChem Cartridge users:


Code:
update <a-jchemuser>.<jchemproperties-table> set prop_value=<jchem-license-key> where prop_name='registration.code';


update <a-jchemuser>.<jchemproperties-table> set prop_value=<jchem-cluster-license-key> where prop_name='registration.code.cluster';


update <a-jchemuser>.<jchemproperties-table> set prop_value=<jchem-cartridge-license-key> where prop_name='registration.code.cartridge';


commit;

User 104a68add6

30-03-2005 15:07:14

Thanks for your help - we have modified the options information to include the license key, and now the cartridge commands have a larger search limit.





We did still get the "read timed out" error message - once, after about 10 -12 steady executions of a jc_contains statement (over the period of a little over a minute). The installation is back in testing, to see if we can more reliably reproduce this error.





My apologies for not stating earlier that we are at v 9i of Oracle.


Julie

ChemAxon aa7c50abf8

31-03-2005 11:43:50

I was not able to reproduce the "Read time out" problem with Oracle 9i either. Please, could you upload the <tomcat-home>/logs/catalina.out file? I am interested in the stack trace output to this file when the problem occurred.

ChemAxon aa7c50abf8

31-03-2005 11:52:03

If the catalina.out file is too long, just post the stack trace with some of the preceding lines so I can have an idea about what happened before the exception occurred.

User 104a68add6

01-04-2005 23:41:26

Sorry for the delay - other fires to put out!





I ran several successful queries, one returning a legal error because my SMILES string was bad (I am not a chemist)...once I get the read timed out error, I get it until I log out and login again. I was able to repeat that several times in testing yesterday. For this test, I stopped at the first read timed out so I wouldn't overload the message.





I ran 3 of these (returns 2539 rows):


select cd_id from structure where jc_contains(cd_smiles, 'CN1C=NC2=C1C(=O)N(C)C(=O)N2C') =1;





Then this bad smiles:


select cd_id from structure where jc_contains(cd_smiles, 'CN1C=NC2=C1C(=O)N(C)C(=O)N2C2') =1;





Then this short one with 36 rows returned:


select cd_id from structure where jc_contains(cd_smiles, 'C1C2(C1)CCC2') =1;





Then I ran the first one again, twice. It failed the second time.








All of that activity, as recorded in catalina.out, follows:





WARNING: Table "JCHEM.STRUCTURE" could not fit into structure cache.


WARNING: Table "JCHEM.STRUCTURE" could not fit into structure cache.


WARNING: Table "JCHEM.STRUCTURE" could not fit into structure cache.


WARNING: Table "JCHEM.STRUCTURE" could not fit into structure cache.


chemaxon.formats.MolFormatException: Line 1: java.io.IOException: Unmatched ring closure number 2 in


SMILES string CN1C=NC2=C1C(=O)N(C)C(=O)N2C2


at chemaxon.util.MolHandler.toMolFormatException(MolHandler.java:667)


at chemaxon.util.MolHandler.importMol(MolHandler.java:655)


at chemaxon.util.MolHandler.setMolecule(MolHandler.java:162)


at chemaxon.jchem.db.JChemSearch.initQuery(JChemSearch.java:2442)


at chemaxon.jchem.db.JChemSearch.init(JChemSearch.java:2512)


at chemaxon.jchem.db.JChemSearch.search1(JChemSearch.java:1956)


at chemaxon.jchem.db.JChemSearch.search(JChemSearch.java:1857)


at chemaxon.jchem.db.JChemSearch.setRunning(JChemSearch.java:1735)


at chemaxon.jchem.db.JChemSearch.run(JChemSearch.java:1755)


at chemaxon.jchem.cartridge.servlets.JChemCached.run(JChemCached.java:676)


at chemaxon.jchem.cartridge.servlets.JChemCached.doPerform(JChemCached.java:521)


at chemaxon.jchem.cartridge.servlets.JChemCached.process(JChemCached.java:100)


at chemaxon.jchem.cartridge.servlets.JChemServletBase.doPost(JChemServletBase.java:215)


at javax.servlet.http.HttpServlet.service(HttpServlet.java:760)


at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)


at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.j


ava:247)


at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)


at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:260)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:643)


at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)


at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)


at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:643)


at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)


at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)


at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2415)


at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:643)


at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:170)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:641)


at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:641)


at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:376)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:641)


at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)


at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)


at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:643)


at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)


at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)


at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:223)


at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:432)


at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11P


rotocol.java:386)


at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:534)


at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:530)


at java.lang.Thread.run(Thread.java:534)


WARNING: Table "JCHEM.STRUCTURE" could not fit into structure cache.


java.net.SocketTimeoutException: Read timed out


at java.net.SocketInputStream.socketRead0(Native Method)


at java.net.SocketInputStream.read(SocketInputStream.java:129)


at org.apache.coyote.http11.InternalInputBuffer.fill(InternalInputBuffer.java:777)


at org.apache.coyote.http11.InternalInputBuffer$InputStreamInputBuffer.doRead(InternalInputB


uffer.java:807)


at org.apache.coyote.http11.filters.IdentityInputFilter.doRead(IdentityInputFilter.java:158)


at org.apache.coyote.http11.InternalInputBuffer.doRead(InternalInputBuffer.java:742)


at org.apache.coyote.Request.doRead(Request.java:431)


at org.apache.coyote.tomcat4.CoyoteInputStream.readBytes(CoyoteInputStream.java:199)


at org.apache.coyote.tomcat4.CoyoteInputStream.read(CoyoteInputStream.java:128)


at chemaxon.jchem.cartridge.servlets.JChemServletBase.checkJChemVersions(JChemServletBase.ja


va:253)


at chemaxon.jchem.cartridge.servlets.JChemServletBase.doPost(JChemServletBase.java:211)


at javax.servlet.http.HttpServlet.service(HttpServlet.java:760)


at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)


at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.j


ava:247)


at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)


at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:260)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:643)


at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)


at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)


at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:643)


at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)


at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)


at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2415)


at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:643)


at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:170)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:641)


at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:641)


at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:376)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:641)


at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)


at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)


at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)


at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Standar


dPipeline.java:643)


at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)


at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)


at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:223)


at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:432)


at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11P


rotocol.java:386)


at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:534)


at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:530)


at java.lang.Thread.run(Thread.java:534)

ChemAxon 9c0afc9aaf

03-04-2005 17:54:21

Hi,





It's probably not connected to the time-out problem, but these warnings are also very important:





WARNING: Table "JCHEM.STRUCTURE" could not fit into structure cache.





This means, that JChem tries to cache this table every time (may take a long time), fails every time, and then runs the search without cache (much slower).





You have to specify a higher heap memory limit for the Java Virtual Machine with the -Xmx parameter.





On possible way to set this is written in the cartridge documentation:





http://www.jchem.com/doc/admin/cartridge.html#server_memory





Different versions of Tomcat might be administered differently, and some Windows versions also ignore these options if run with the default Start Menu icon, so I also recommend to read this page:





http://www.jchem.com/doc/admin/tomcat.html





Best regards,





Szilard

ChemAxon aa7c50abf8

04-04-2005 18:07:13

Julie,





Please, could you post the attributes of the relevant Tomcat connector in your <tomcat-home>/conf/server.xml file. I am especially interested in the time out attribute(s).





Thank you!





Peter

User 104a68add6

04-04-2005 18:21:18

Thank you for the info on the jvm cache...I'll work with our Tomcat expert so we can get that up to a higher value.





Here is the info you asked for from the server.xml file:








<!-- Define a non-SSL Coyote HTTP/1.1 Connector on port 8080 -->


<Connector className="org.apache.coyote.tomcat4.CoyoteConnector"


port="8080" minProcessors="5" maxProcessors="75"


enableLookups="true" redirectPort="8443"


acceptCount="100" debug="0" connectionTimeout="20000"


useURIValidationHack="false" disableUploadTimeout="true" />


<!-- Note : To disable connection timeouts, set connectionTimeout value


to -1 -->








Regards,


Julie

ChemAxon aa7c50abf8

05-04-2005 21:18:26

No real clues from the Tomcat stack trace. Could you post the Oracle trace for the session where the problem occurred?





Are the "Read timeout" errors always preceded by some other errors? Are the "Read timeout" errors preceded immediately by some other error or are they sometimes preceded by successful SQL calls?





Do the SQL calls triggerring the "Read timeout" error wait for significant amount of time before failing? (I. e. do you perceive the timeout nature of the error justified by the amount of time spent by the call waiting to return?)





The 20000 timeout value should be OK unless you have an extremely busy Oracle (or Tomcat) system. I use the same setting and have been still unable to reproduce the "Read timeout" problem.

User 104a68add6

05-04-2005 21:32:05

I will try to get a chunk of the Oracle trace to look at....please be patient on this one.





The read timed out error occurs after one or more successful queries. Only once did I get it as soon as I had re-logged in.





I wait longer to get the read timed out error than I do for a non-cached query that is successful. Maybe 10 - 20 seconds (I can set timing on if you'd like to have an exact value). I can tell when I am about to get a read timed out :-)





Our system is not terribly busy, nor is Tomcat - this is a test environment, so we generally restart Tomcat at will. I did this when increasing the memory size as you folks recommended (and the cache errors stopped - thank you!)





Regards,


Julie

User 104a68add6

11-04-2005 22:34:58

Apologies for the delay, I finally have a couple of session trace files I will attach.





I did notice that while doing the jc_contains searches, if I did several within 10 - 15 seconds of one another the results would be OK. But if I waited for 30 seconds to a minute, I could almost always guarantee that the next query I ran would get a read timed out. Don't know what idle time could do to interfere with anything, but as I am grasping at straws I thought I would mention it.





Regards,


Julie

ChemAxon aa7c50abf8

12-04-2005 14:02:24

I finally managed to reproduce the problem fairly reliably in my environment. The key to reproducing it is to setup Tomcat on a separate machine and to use Oracle version 9i. With Oracle 10g I could not reproduce the problem even with Tomcat being set up on a different machine.
Quote:
But if I waited for 30 seconds to a minute, I could almost always guarantee that the next query I ran would get a read timed out.
I confirm that this is the behavior with Oracle 9i.





After analyzing the TCP packets exchanged I found out that at the beginning of the search Oracle correctly sends the header of the HTTP message containing the search parameters. The packet with the HTTP header is then correctly acknowledged by Tomcat. The problem is that Oracle fails to transmit the content of the HTTP message.





The source of the problem therefore seems to be somewhat beyond our control. I will nonetheless try fiddling a bit with the HTTP header parameters (keep-alive comes to my mind first) to see if changing them makes any difference.





Regards,


Peter

ChemAxon aa7c50abf8

13-04-2005 13:07:02

I have extended my investigation of the network traffic between Oracle and Tomcat and found out that 20 seconds (the socket timeout value configured for Tomcat) after the last successful cartridge search operation, Tomcat unilaterally closes the TCP connection. Interestingly, as the user initiates the next search operation, Oracle starts sending the search parameters over this same half-closed TCP connection. Tomcat rejects any more data on this connection. From this point on the observed sequence is the same as is described in my previous posting. Oracle initiates a new TCP connection which is accepted by Tomcat. Oracle sends the HTTP header over the new TCP connection, but fails to send the content, which results in Tomcat generating a timeout error after 20 seconds.





The above observations mean that you have to wait exactly 20 seconds after the last successful search operation to reproduce the timeout problem. This lead me to follow your initial intuitive suggestion to increase the connection timeout value in Tomcat from the default 20 seconds. It did work. I set the timeout to 1 hour and was still able to issue queries in the same Oracle session even after more than 1 hour of idle time.





For the moment, I suggest the following workaround: set the timeout value in Tomcat significantly higher than 20 seconds (e. g. somewhere at 3600 seconds) and implement your application using JChem Cartridge so as to restart any single Oracle session after it has been idle for slightly less time than the Tomcat timeout value. This will give a manageable Oracle session restart interval and at the same time the number of badly-behaved open connections in Tomcat (if there are any) will still remain at a probably tolerable level (resources will be recovered after at most the configured timeout -- e. g. after 1 hour).





In the meantime, I continue trying to find out if we can do any better than that (i. e. solution without having to restart Oracle sessions).





Regards


Peter