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

ORA-29902

User 4140faeba5

21-12-2009 12:41:22

Hi.


JCHEM_CORE_PKG.GETENVIRONMENT()
--------------------------------------------------------------------------------
Oracle environment:
Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
PL/SQL Release 11.1.0.7.0 - Production
CORE 11.1.0.7.0 Production
TNS for Linux: Version 11.1.0.7.0 - Production
NLSRTL Version 11.1.0.7.0 - Production

JChem Server environment:
Java VM vendor: Sun Microsystems Inc.
Java version: 1.5.0_12
Java VM version: 1.5.0_12-b04

JCHEM_CORE_PKG.GETENVIRONMENT()
--------------------------------------------------------------------------------
JChem version: 5.2.3_1
JChem Index version: 5020100
JDBC driver version: 11.1.0.7.0-Production


 


I have run into some trouble searching.


If I search from sqlplus


SQL> select SUFFIX from act_compound.JCSALT_MOLTABLE where jc_compareb(cd_structure,(select bmolfile from ACT_HIVE.tempmolfile where pkey=93324004), 't:e HCountMatching:G doubleBondStereo:M exactIsotopeMatching:y absoluteStereo:c exactStereoMatching:y')=1;

SUFFIX
----------
C
C

SQL>
I get the correct answer.


If I do the same query from my application which uses OCI, I get the following


select SUFFIX from act_compound.JCSALT_MOLTABLE where jc_compareb(cd_structure,(select bmolfile from ACT_HIVE.tempmolfile where pkey=93324004), 't:e HCountMatching:G doubleBondStereo:M exactIsotopeMatching:y absoluteStereo:c exactStereoMatching:y')=1
Error> ORA-29902: error in executing ODCIIndexStart() routine
ORA-29532: Java call terminated by uncaught Java exception: java.lang.NullPointerException
ORA-06512: at "JCHEM.JCHEM_CORE_PKG", line 49
ORA-06512: at "JCHEM.JC_IDXTYPE_IM", line 394 (HiveServer.bee:94)


Error> ORA-29902: error in executing ODCIIndexStart() routine
ORA-29532: Java call terminated by uncaught Java exception: java.lang.NullPointerException
ORA-06512: at "JCHEM.JCHEM_CORE_PKG", line 49
ORA-06512: at "JCHEM.JC_IDXTYPE_IM", line 394
(HiveServer.bee:94)


 


Any idea what I might have missed, or what might be wrong ?

User 4140faeba5

21-12-2009 14:16:26

More info.


This is from Oracle trace.


Trace file /u01/oracle/product/diag/rdbms/star/star/trace/star_ora_437.trc
Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/11R1_64bit
System name: Linux
Node name: vader
Release: 2.6.5-7.283-smp
Version: #1 SMP Wed Nov 29 16:55:53 UTC 2006
Machine: x86_64
Instance name: star
Redo thread mounted by this instance: 1
Oracle process number: 75
Unix process pid: 437, image: oracle@vader


*** 2009-12-21 15:04:39.086
*** SESSION ID:(158.16224) 2009-12-21 15:04:39.086
*** CLIENT ID:() 2009-12-21 15:04:39.086
*** SERVICE NAME:(SYS$USERS) 2009-12-21 15:04:39.086
*** MODULE NAME:(bee.exe) 2009-12-21 15:04:39.086
*** ACTION NAME:() 2009-12-21 15:04:39.086

Exception in thread "Root Thread" java.lang.NullPointerException
at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.init0(JCartIndexDescriptor.java)
at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.<init>(JCartIndexDescriptor.java)
at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.get(JCartIndexDescriptor.java)
at chemaxon.jchem.cartridge.JFunctions.checkTableVersion(JFunctions.java)
oracle@vader:~/product/diag/rdbms/star/star/trace>



The operation works fine against tables created by an older version of jcman.

ChemAxon aa7c50abf8

21-12-2009 15:13:36

Hi,


You can turn on full logging in the Oracle-resident parts of JChem Cartridge in the current session by executing:


call jcart_logger.set_log_level('chemaxon', 4)

I suspect that there must be some higher level differences between your sqlplus test environment and the OCI test environment. I find it unlikely that the difference in the client tool causes the problem. Are you using the same tables in the same schema?


Peter

User 4140faeba5

22-12-2009 07:45:18

Ok, I turned on full logging.


This is the trace file when I run the application against the table setup created with an older version of jchem.


"Trace file /u01/oracle/product/diag/rdbms/star/star/trace/star_ora_17903.trc
Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/11R1_64bit
System name:    Linux
Node name:    vader
Release:    2.6.5-7.283-smp
Version:    #1 SMP Wed Nov 29 16:55:53 UTC 2006
Machine:    x86_64
Instance name: star
Redo thread mounted by this instance: 1
Oracle process number: 54
Unix process pid: 17903, image: oracle@vader


*** 2009-12-22 08:21:39.662
*** SESSION ID:(157.51266) 2009-12-22 08:21:39.662
*** CLIENT ID:() 2009-12-22 08:21:39.662
*** SERVICE NAME:(star) 2009-12-22 08:21:39.662
*** MODULE NAME:(beed@vader (TNS V1-V3)) 2009-12-22 08:21:39.662
*** ACTION NAME:() 2009-12-22 08:21:39.662
 
2009-12-22 08:21:39.649 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:21:39.662 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 08:21:39.663 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM chemspec.jc_idx_property WHERE prop_name = ?
2009-12-22 08:21:39.664 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:21:39.665 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for CHEMSPEC.IDX_JCHEM_STRUCT
2009-12-22 08:21:39.666 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: "SELECT prop_value FROM jchem.jchemproperties WHERE prop_name = ?" with ?1=table.CHEMSPEC.JCMOL_MOLTABLE.validityTimestamp
2009-12-22 08:21:39.694 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:21:39.695 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 08:21:39.695 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM chemspec.jc_idx_property WHERE prop_name = ?
2009-12-22 08:21:39.695 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:21:40.140 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:21:40.141 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 08:21:40.142 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM chemspec.jc_idx_property WHERE prop_name = ?
2009-12-22 08:21:40.142 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:21:40.143 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for CHEMSPEC.IDX_JCHEM_STRUCT
2009-12-22 08:21:40.143 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: "SELECT prop_value FROM jchem.jchemproperties WHERE prop_name = ?" with ?1=table.CHEMSPEC.JCMOL_MOLTABLE.validityTimestamp
2009-12-22 08:21:40.144 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:21:40.145 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 08:21:40.145 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM chemspec.jc_idx_property WHERE prop_name = ?
2009-12-22 08:21:40.145 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:21:40.145 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for CHEMSPEC.IDX_JCHEM_STRUCT
2009-12-22 08:21:40.149 [9429272, MIMI, CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: evaluate: ctColName=null

*** 2009-12-22 08:21:44.644
2009-12-22 08:21:44.644 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=BCPVS, idxName=IDX_JCHEM_STRUCT_SALT, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:21:44.645 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=BCPVS.IDX_JCHEM_STRUCT_SALT.idxTable
2009-12-22 08:21:44.645 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM bcpvs.jc_idx_property WHERE prop_name = ?
2009-12-22 08:21:44.697 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:21:44.711 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_STRUCT_SALT
2009-12-22 08:21:44.711 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: "SELECT prop_value FROM jchem.jchemproperties WHERE prop_name = ?" with ?1=table.BCPVS.JCSALT_MOLTABLE.validityTimestamp
2009-12-22 08:21:44.789 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch outer BEGIN
2009-12-22 08:21:44.790 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch BEGIN
2009-12-22 08:21:44.790 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=BCPVS, idxName=IDX_JCHEM_STRUCT_SALT, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:21:44.790 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=BCPVS.IDX_JCHEM_STRUCT_SALT.idxTable
2009-12-22 08:21:44.790 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM bcpvs.jc_idx_property WHERE prop_name = ?
2009-12-22 08:21:44.790 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:21:44.791 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_STRUCT_SALT
2009-12-22 08:21:44.791 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_STRUCT_SALT
2009-12-22 08:21:45.034 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendQueryForCached BEGIN
2009-12-22 08:21:45.076 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: Using SRMI for transport.
2009-12-22 08:21:45.198 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.jcservcli.JchemSearchResultSRmiCli: Constructed using JchemSearchImpl_Stub[UnicastRef [liveRef: [endpoint:[localhost:34834](remote),objID:[-4fbf512e:125b149c1ef:-8000, 5]]]]
2009-12-22 08:21:45.198 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendQueryForCached END
2009-12-22 08:21:45.198 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.addScanResult: scannum=187421
2009-12-22 08:21:45.198 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch outer END
2009-12-22 08:21:45.226 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187421

*** 2009-12-22 08:21:45.328
2009-12-22 08:21:45.328 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): tableScanResult..getNextHits() returns 2 hit(s).
2009-12-22 08:21:45.783 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createCdIdResultSet: hit count=2
2009-12-22 08:21:45.783 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=2, idArrayIdx=0
2009-12-22 08:21:45.783 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 2
2009-12-22 08:21:45.783 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=2
2009-12-22 08:21:45.784 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: getRowids: scannum=187421
2009-12-22 08:21:45.784 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187421
2009-12-22 08:21:45.784 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=2, idArrayIdx=0
2009-12-22 08:21:45.784 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 2
2009-12-22 08:21:45.784 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=2
2009-12-22 08:21:45.784 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=2, idArrayIdx=0
2009-12-22 08:21:45.784 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 2
2009-12-22 08:21:45.784 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: BEGIN
2009-12-22 08:21:45.785 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: setting create statement as ref cursor ON...
2009-12-22 08:21:45.785 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: about to createStatement...
2009-12-22 08:21:45.785 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createStatementString count=2
2009-12-22 08:21:45.785 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createStatementString END
2009-12-22 08:21:45.785 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: exec' query
2009-12-22 08:21:45.787 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: query exec'd
2009-12-22 08:21:45.788 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: setting create statement as ref cursor ON...
2009-12-22 08:21:45.792 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: END
2009-12-22 08:21:46.058 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187421
2009-12-22 08:21:46.058 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 0
2009-12-22 08:21:46.058 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=0
2009-12-22 08:21:46.059 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): tableScanResult..getNextHits() returns null: no more results.
2009-12-22 08:21:46.074 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.closeScanResult: scannum=187421, jcResultSet=[chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet]chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet@2ee11488

*** 2009-12-22 08:21:46.336
2009-12-22 08:21:46.336 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=BCPVS, idxName=IDX_JCHEM_SEP, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:21:46.336 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=BCPVS.IDX_JCHEM_SEP.idxTable
2009-12-22 08:21:46.337 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM bcpvs.jc_idx_property WHERE prop_name = ?
2009-12-22 08:21:46.337 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:21:46.342 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_SEP
2009-12-22 08:21:46.342 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: "SELECT prop_value FROM jchem.jchemproperties WHERE prop_name = ?" with ?1=table.BCPVS.JCSEPMOL_MOLTABLE.validityTimestamp
2009-12-22 08:21:46.348 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch outer BEGIN
2009-12-22 08:21:46.349 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch BEGIN
2009-12-22 08:21:46.349 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=BCPVS, idxName=IDX_JCHEM_SEP, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:21:46.349 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=BCPVS.IDX_JCHEM_SEP.idxTable
2009-12-22 08:21:46.349 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM bcpvs.jc_idx_property WHERE prop_name = ?
2009-12-22 08:21:46.349 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:21:46.349 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_SEP
2009-12-22 08:21:46.351 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_SEP
2009-12-22 08:21:46.352 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendQueryForCached BEGIN
2009-12-22 08:21:46.352 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: Using SRMI for transport.
2009-12-22 08:21:46.357 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.jcservcli.JchemSearchResultSRmiCli: Constructed using JchemSearchImpl_Stub[UnicastRef [liveRef: [endpoint:[localhost:34834](remote),objID:[-4fbf512e:125b149c1ef:-8000, 5]]]]
2009-12-22 08:21:46.357 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendQueryForCached END
2009-12-22 08:21:46.358 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.addScanResult: scannum=187422
2009-12-22 08:21:46.358 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch outer END
2009-12-22 08:21:46.359 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187422

*** 2009-12-22 08:22:08.029
2009-12-22 08:22:08.029 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): tableScanResult..getNextHits() returns 1 hit(s).
2009-12-22 08:22:08.030 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createCdIdResultSet: hit count=1
2009-12-22 08:22:08.030 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=1, idArrayIdx=0
2009-12-22 08:22:08.030 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 1
2009-12-22 08:22:08.030 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=1
2009-12-22 08:22:08.030 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: getRowids: scannum=187422
2009-12-22 08:22:08.030 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187422
2009-12-22 08:22:08.030 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=1, idArrayIdx=0
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 1
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=1
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=1, idArrayIdx=0
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 1
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: BEGIN
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: setting create statement as ref cursor ON...
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: about to createStatement...
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createStatementString count=1
2009-12-22 08:22:08.031 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createStatementString END
2009-12-22 08:22:08.032 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: exec' query
2009-12-22 08:22:08.033 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: query exec'd
2009-12-22 08:22:08.034 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: setting create statement as ref cursor ON...
2009-12-22 08:22:08.037 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: END
2009-12-22 08:22:08.060 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187422
2009-12-22 08:22:08.060 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 0
2009-12-22 08:22:08.060 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=0
2009-12-22 08:22:08.061 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): tableScanResult..getNextHits() returns null: no more results.
2009-12-22 08:22:08.075 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.closeScanResult: scannum=187422, jcResultSet=[chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet]chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet@31e906e3
2009-12-22 08:22:08.303 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=BCPVS, idxName=IDX_JCHEM_STRUCT_JCMOL, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:22:08.304 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=BCPVS.IDX_JCHEM_STRUCT_JCMOL.idxTable
2009-12-22 08:22:08.304 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM bcpvs.jc_idx_property WHERE prop_name = ?
2009-12-22 08:22:08.305 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:22:08.314 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_STRUCT_JCMOL
2009-12-22 08:22:08.314 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: "SELECT prop_value FROM jchem.jchemproperties WHERE prop_name = ?" with ?1=table.BCPVS.JCMOL_MOLTABLE.validityTimestamp
2009-12-22 08:22:08.328 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch outer BEGIN
2009-12-22 08:22:08.328 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch BEGIN
2009-12-22 08:22:08.328 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=BCPVS, idxName=IDX_JCHEM_STRUCT_JCMOL, idxPartition=null, evenIfJChemTable=false
2009-12-22 08:22:08.328 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=BCPVS.IDX_JCHEM_STRUCT_JCMOL.idxTable
2009-12-22 08:22:08.329 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM bcpvs.jc_idx_property WHERE prop_name = ?
2009-12-22 08:22:08.329 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 08:22:08.329 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_STRUCT_JCMOL
2009-12-22 08:22:08.330 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for BCPVS.IDX_JCHEM_STRUCT_JCMOL
2009-12-22 08:22:08.330 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendQueryForCached BEGIN
2009-12-22 08:22:08.331 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: Using SRMI for transport.
2009-12-22 08:22:08.343 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.jcservcli.JchemSearchResultSRmiCli: Constructed using JchemSearchImpl_Stub[UnicastRef [liveRef: [endpoint:[localhost:34834](remote),objID:[-4fbf512e:125b149c1ef:-8000, 5]]]]
2009-12-22 08:22:08.343 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendQueryForCached END
2009-12-22 08:22:08.343 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.addScanResult: scannum=187423
2009-12-22 08:22:08.344 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch outer END
2009-12-22 08:22:08.344 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187423

*** 2009-12-22 08:22:31.854
2009-12-22 08:22:31.853 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): tableScanResult..getNextHits() returns 1 hit(s).
2009-12-22 08:22:31.854 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createCdIdResultSet: hit count=1
2009-12-22 08:22:31.854 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=1, idArrayIdx=0
2009-12-22 08:22:31.854 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 1
2009-12-22 08:22:31.854 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=1
2009-12-22 08:22:31.854 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: getRowids: scannum=187423
2009-12-22 08:22:31.854 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187423
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=1, idArrayIdx=0
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 1
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=1
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=1, idArrayIdx=0
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 1
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: BEGIN
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: setting create statement as ref cursor ON...
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: about to createStatement...
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createStatementString count=1
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createStatementString END
2009-12-22 08:22:31.855 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: exec' query
2009-12-22 08:22:31.857 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: query exec'd
2009-12-22 08:22:31.857 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: setting create statement as ref cursor ON...
2009-12-22 08:22:31.861 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: END
2009-12-22 08:22:31.887 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187423
2009-12-22 08:22:31.887 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 0
2009-12-22 08:22:31.887 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingRowids()=0
2009-12-22 08:22:31.888 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): tableScanResult..getNextHits() returns null: no more results.
2009-12-22 08:22:31.903 [9429272, MIMI, BCPVS]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.closeScanResult: scannum=187423, jcResultSet=[chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet]chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet@a71dc9d1
"


I then switched to use the table setup created with the current jchem version.


here is the trace from this.


"Trace file /u01/oracle/product/diag/rdbms/star/star/trace/star_ora_16016.trc
Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/11R1_64bit
System name:    Linux
Node name:    vader
Release:    2.6.5-7.283-smp
Version:    #1 SMP Wed Nov 29 16:55:53 UTC 2006
Machine:    x86_64
Instance name: star
Redo thread mounted by this instance: 1
Oracle process number: 59
Unix process pid: 16016, image: oracle@vader


*** 2009-12-22 07:58:51.875
*** SESSION ID:(207.18021) 2009-12-22 07:58:51.875
*** CLIENT ID:() 2009-12-22 07:58:51.875
*** SERVICE NAME:(star) 2009-12-22 07:58:51.875
*** MODULE NAME:(beed@vader (TNS V1-V3)) 2009-12-22 07:58:51.875
*** ACTION NAME:() 2009-12-22 07:58:51.875
 
2009-12-22 07:58:51.827 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=ACT_CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, evenIfJChemTable=false
2009-12-22 07:58:51.875 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=ACT_CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 07:58:51.876 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM act_chemspec.jc_idx_property WHERE prop_name = ?
2009-12-22 07:58:51.901 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 07:58:51.939 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for ACT_CHEMSPEC.IDX_JCHEM_STRUCT
2009-12-22 07:58:51.939 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: "SELECT prop_value FROM jchem.jchemproperties WHERE prop_name = ?" with ?1=table.ACT_CHEMSPEC.JCMOL_MOLTABLE.validityTimestamp
2009-12-22 07:58:52.029 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=ACT_CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, evenIfJChemTable=false
2009-12-22 07:58:52.030 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=ACT_CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 07:58:52.030 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM act_chemspec.jc_idx_property WHERE prop_name = ?
2009-12-22 07:58:52.030 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 07:58:52.404 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=ACT_CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, evenIfJChemTable=false
2009-12-22 07:58:52.405 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=ACT_CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 07:58:52.405 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM act_chemspec.jc_idx_property WHERE prop_name = ?
2009-12-22 07:58:52.406 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 07:58:52.406 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for ACT_CHEMSPEC.IDX_JCHEM_STRUCT
2009-12-22 07:58:52.407 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: "SELECT prop_value FROM jchem.jchemproperties WHERE prop_name = ?" with ?1=table.ACT_CHEMSPEC.JCMOL_MOLTABLE.validityTimestamp
2009-12-22 07:58:52.408 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=ACT_CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, evenIfJChemTable=false
2009-12-22 07:58:52.409 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=ACT_CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 07:58:52.409 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM act_chemspec.jc_idx_property WHERE prop_name = ?
2009-12-22 07:58:52.409 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 07:58:52.409 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for ACT_CHEMSPEC.IDX_JCHEM_STRUCT
2009-12-22 07:58:52.415 [9428984, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: evaluate: ctColName=null

*** 2009-12-22 07:58:57.035
2009-12-22 07:58:57.034 [9428984, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=ACT_COMPOUND, idxName=IDX_JCHEM_STRUCT_SALT, idxPartition=null, evenIfJChemTable=false
2009-12-22 07:58:57.035 [9428984, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=ACT_COMPOUND.IDX_JCHEM_STRUCT_SALT.idxTable
2009-12-22 07:58:57.036 [9428984, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM act_compound.jc_idx_property WHERE prop_name = ?
2009-12-22 07:58:57.070 [9428984, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
Exception in thread "Root Thread" java.lang.NullPointerException
    at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.init0(JCartIndexDescriptor.java)
    at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.<init>(JCartIndexDescriptor.java)
    at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.get(JCartIndexDescriptor.java)
    at chemaxon.jchem.cartridge.JFunctions.checkTableVersion(JFunctions.java)
".


I have a slight feeling the I'm hitting the same bug as in http://chemaxon.com/forum/ftopic5228.html


or, can you make out from the trace where I have missed to grant privileges ?

ChemAxon aa7c50abf8

22-12-2009 13:20:23

I see that after switching to the current jchem version, you successfully searched using the ACT_CHEMSPEC.IDX_JCHEM_STRUCT index and then you started searching using the ACT_COMPOUND.IDX_JCHEM_STRUCT_SALT which aborted. Is this correct?


What happens if you start a new session and reverse the search order: searching first by  ACT_COMPOUND.IDX_JCHEM_STRUCT_SALT then by ACT_CHEMSPEC.IDX_JCHEM_STRUCT? If searching by  ACT_COMPOUND.IDX_JCHEM_STRUCT_SALT first is successful and then searching by ACT_CHEMSPEC.IDX_JCHEM_STRUCT fails, this is the earlier problem you mentioned.


Thanks


Peter

User 4140faeba5

22-12-2009 13:42:12

Testing that from sqlplus gives the following:


"call jcart_logger.set_log_level('chemaxon', 4);

Call completed.

SQL> select SUFFIX from act_compound.JCSALT_MOLTABLE where jc_compareb(cd_structure,(select bmolfile from ACT_HIVE.tempmolfile where pkey=93324582), 't:e HCountMatching:G doubleBondStereo:M exactIsotopeMatching:y absoluteStereo:c exactStereoMatching:y')=1 ;

SUFFIX
----------
C
C

SQL> select regno from act_chemspec.jcmol_moltable  where jc_compareb(cd_structure,(select bmolfile from ACT_HIVE.tempmolfile where pkey=93324582), 't:e HCountMatching:G doubleBondStereo:M exactIsotopeMatching:y absoluteStereo:c exactStereoMatching:y')=1 ;
select regno from act_chemspec.jcmol_moltable  where jc_compareb(cd_structure,(select bmolfile from ACT_HIVE.tempmolfile where pkey=93324582), 't:e HCountMatching:G doubleBondStereo:M exactIsotopeMatching:y absoluteStereo:c exactStereoMatching:y')=1
*
ERROR at line 1:
ORA-29902: error in executing ODCIIndexStart() routine
ORA-29532: Java call terminated by uncaught Java exception:
java.lang.NullPointerException
ORA-06512: at "JCHEM.JCHEM_CORE_PKG", line 49
ORA-06512: at "JCHEM.JC_IDXTYPE_IM", line 394
"


Information from trace:


"Trace file /u01/oracle/product/diag/rdbms/star/star/trace/star_ora_19462.trc
Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/11R1_64bit
System name:    Linux
Node name:      vader
Release:        2.6.5-7.283-smp
Version:        #1 SMP Wed Nov 29 16:55:53 UTC 2006
Machine:        x86_64
Instance name: star
Redo thread mounted by this instance: 1
Oracle process number: 52
Unix process pid: 19462, image: oracle@vader (TNS V1-V3)


*** 2009-12-22 14:32:48.874
*** SESSION ID:(169.9342) 2009-12-22 14:32:48.874
*** CLIENT ID:() 2009-12-22 14:32:48.874
*** SERVICE NAME:(SYS$USERS) 2009-12-22 14:32:48.874
*** MODULE NAME:(SQL*Plus) 2009-12-22 14:32:48.874
*** ACTION NAME:() 2009-12-22 14:32:48.874

Exception in thread "Root Thread" java.lang.NullPointerException
        at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.init0(JCartIndexDescriptor.java)
        at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.<init>(JCartIndexDescriptor.java)
        at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.get(JCartIndexDescriptor.java)
        at chemaxon.jchem.cartridge.JFunctions.checkTableVersion(JFunctions.java)

*** 2009-12-22 14:35:10.133
2009-12-22 14:35:10.131 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=ACT_COMPOUND, idxName=IDX_JCHEM_STRUCT_SALT, idxPartition=nul\
l, evenIfJChemTable=false
2009-12-22 14:35:10.133 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=ACT_COMPOUND.IDX_JCHEM_STRUCT_SALT.idxTable
2009-12-22 14:35:10.134 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM act_compound.jc_idx_property\
 WHERE prop_name = ?
2009-12-22 14:35:10.134 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 14:35:10.136 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for ACT_COMPOUND.IDX_JCHEM_STR\
UCT_SALT
2009-12-22 14:35:10.136 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: "SELECT prop_value FROM jchem.jchemproperties WHERE\
 prop_name = ?" with ?1=table.ACT_COMPOUND.JCSALT_MOLTABLE.validityTimestamp
2009-12-22 14:35:10.137 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch outer BEGIN
2009-12-22 14:35:10.138 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch BEGIN
2009-12-22 14:35:10.138 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=ACT_COMPOUND, idxName=IDX_JCHEM_STRUCT_SALT, idxPartition=nul\
l, evenIfJChemTable=false
2009-12-22 14:35:10.138 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=ACT_COMPOUND.IDX_JCHEM_STRUCT_SALT.idxTable
2009-12-22 14:35:10.138 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM act_compound.jc_idx_property\
 WHERE prop_name = ?
2009-12-22 14:35:10.138 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
2009-12-22 14:35:10.139 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for ACT_COMPOUND.IDX_JCHEM_STR\
UCT_SALT
2009-12-22 14:35:10.139 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Returning jchem.jchemproperties for ACT_COMPOUND.IDX_JCHEM_STR\
UCT_SALT
2009-12-22 14:35:10.140 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendQueryForCached BEGIN
2009-12-22 14:35:10.140 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: Using SRMI for transport.
2009-12-22 14:35:10.140 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: Using SRMI for transport.
2009-12-22 14:35:10.148 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.jcservcli.JchemSearchResultSRmiCli: Constructed using JchemSearchImpl_Stub[UnicastR\
ef [liveRef: [endpoint:[localhost:34834](remote),objID:[-4fbf512e:125b149c1ef:-8000, 5]]]]
2009-12-22 14:35:10.148 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendQueryForCached END
2009-12-22 14:35:10.148 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.addScanResult: scannum=187442
2009-12-22 14:35:10.148 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.sendBatch outer END
2009-12-22 14:35:10.149 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187442
2009-12-22 14:35:10.172 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): tableScanResult..getNextHits(\
) returns 2 hit(s).
2009-12-22 14:35:10.172 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createCdIdResultSet: hit count=2
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=2, idArrayIdx=0
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 2
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingR\
owids()=2
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: getRowids: scannum=187442
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187442
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=2, idArrayIdx=0
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 2
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingR\
owids()=2
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: cdIdArrayLength=2, idArrayIdx=0
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 2
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: BEGIN
2009-12-22 14:35:10.173 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: setting create statement as ref cursor ON...
2009-12-22 14:35:10.174 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: about to createStatement...
2009-12-22 14:35:10.174 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createStatementString count=2
2009-12-22 14:35:10.174 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: createStatementString END
2009-12-22 14:35:10.174 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: exec' query
2009-12-22 14:35:10.174 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: resultSetFromStatement: query exec'd
2009-12-22 14:35:10.175 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: setting create statement as ref cursor ON...
2009-12-22 14:35:10.178 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: prepareExec: END
2009-12-22 14:35:10.178 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.getScanResult: scannum=187442
2009-12-22 14:35:10.179 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.CdIdResultSet: getNrRemainingRowids: returning 0
2009-12-22 14:35:10.179 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): cdIdResultSet.getNrRemainingR\
owids()=0
2009-12-22 14:35:10.179 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet: getNrRemainingRowids(): tableScanResult..getNextHits(\
) returns null: no more results.
2009-12-22 14:35:10.192 [9436412, MIMI, ACT_COMPOUND]: DEBUG - chemaxon.jchem.cartridge.JFunctions: JFunctions.closeScanResult: scannum=187442, jcResultSet=[chemaxon.jchem\
.cartridge.resultset.EarlyCdIdResultSet]chemaxon.jchem.cartridge.resultset.EarlyCdIdResultSet@24e1fe80

*** 2009-12-22 14:35:17.944
2009-12-22 14:35:17.943 [9436412, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxSchema=ACT_CHEMSPEC, idxName=IDX_JCHEM_STRUCT, idxPartition=null, ev\
enIfJChemTable=false
2009-12-22 14:35:17.944 [9436412, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: masterPropName=ACT_CHEMSPEC.IDX_JCHEM_STRUCT.idxTable
2009-12-22 14:35:17.944 [9436412, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JcMetaDataFunctions: Executing: SELECT prop_value FROM act_chemspec.jc_idx_property\
 WHERE prop_name = ?
2009-12-22 14:35:17.944 [9436412, MIMI, ACT_CHEMSPEC]: DEBUG - chemaxon.jchem.cartridge.JFunctions: idxTblQName=null
Exception in thread "Root Thread" java.lang.NullPointerException
        at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.init0(JCartIndexDescriptor.java)
        at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.<init>(JCartIndexDescriptor.java)
        at chemaxon.jchem.cartridge.structs.JCartIndexDescriptor.get(JCartIndexDescriptor.java)
        at chemaxon.jchem.cartridge.JFunctions.checkTableVersion(JFunctions.java)
".


So, I am hitting the bug I earlier mentioned.


Seeing that you have introduced a new bug with tanimoto searches (http://www.chemaxon.com/forum/ftopic5697.html), how soon will you have a version out that does not have that bug ?

ChemAxon aa7c50abf8

22-12-2009 15:08:46

The fix for that bug will be released with 5.3 in early January.


Peter