Project

General

Profile

« Previous | Next » 

Revision 5207

Added by daigle about 14 years ago

Beef up log messages

View differences:

src/edu/ucsb/nceas/metacat/DocumentImpl.java
542 542
            sql.append(docid).append("'");
543 543
        }
544 544
        pstmt = dbconn.prepareStatement(sql.toString());
545
        logMetacat.debug("DocumentImpl.modifyRecordsInGivenTable - executing SQL: " + pstmt.toString());
545 546
        pstmt.execute();
546 547
        pstmt.close();
547 548
       
......
1598 1599

  
1599 1600
//        String doc = docid;
1600 1601
      double afterPutNode = System.currentTimeMillis()/1000;
1601
      logMetacat.debug("DocumentImpl.buildIndex - The time for put node id into map is "+(afterPutNode - start));
1602
      logMetacat.debug("DocumentImpl.buildIndex - The time to put node id into map is " + (afterPutNode - start));
1602 1603
      double afterDelete = 0;
1603 1604
        // Opening separate db connection for deleting and writing
1604 1605
        // XML Index -- be sure that it is all in one db transaction
......
1662 1663
                // Lastly, update the xml_path_index table
1663 1664
                if(!pathsFound.isEmpty()){
1664 1665
                    try {
1666
                        logMetacat.debug("DocumentImpl.buildIndex - updating path index");
1667
                    	
1665 1668
                    	updatePathIndex(dbConn, pathsFound);
1666 1669
                    } catch (SQLException sqle) {
1667 1670
                    	
......
1707 1710
								+ docid);
1708 1711
			}
1709 1712
		} catch (PropertyNotFoundException pnfe) {
1710
			logMetacat.error("DocumentImpl.buildIndex -  Could not get 'runSpatialOption' property.  Spatial " 
1713
			logMetacat.error("DocumentImpl.buildIndex - Could not get 'runSpatialOption' property.  Spatial " 
1711 1714
					+ "cache not run for docid: " + docid + " : " + pnfe.getMessage());
1712 1715
		} catch (StringIndexOutOfBoundsException siobe) {
1713 1716
			logMetacat.error("DocumentImpl.buildIndex -  String indexing problem.  Spatial " 
......
1757 1760
                if (current.getNodeType().equals("ATTRIBUTE")) {
1758 1761
                    currentName = "@" + currentName;
1759 1762
                }
1760
                logMetacat.debug("A: " + currentName +"\n");
1763
                logMetacat.debug("DocumentImpl.traverseParents - A: " + currentName +"\n");
1761 1764
                if ( currentName != null ) {
1762 1765
                  if ( !currentName.equals("") ) {
1763 1766
                    pathList.put(currentName, new PathIndexEntry(leafNodeId,
......
1766 1769
                }
1767 1770
				if (pathsForIndexing.contains(currentName)
1768 1771
						&& leafData.trim().length() != 0) {
1769
					logMetacat.debug("paths found for indexing: " + currentName);
1772
					logMetacat.debug("DocumentImpl.traverseParents - paths found for indexing: " + currentName);
1770 1773
					pathsFoundForIndexing.put(currentName, new PathIndexEntry(
1771 1774
							leafNodeId, currentName, docid, leafParentId, leafData,
1772 1775
							leafDataNumerical));
......
1785 1788
            String path = current.getNodeName() + children;
1786 1789
            
1787 1790
            if ( !children.equals("") ) {
1788
                logMetacat.debug("B: " + path +"\n");
1791
                logMetacat.debug("DocumentImpl.traverseParents - B: " + path +"\n");
1789 1792
                pathList.put(path, new PathIndexEntry(leafNodeId, path, docid,
1790 1793
                    doctype, parentId));
1791 1794
				if (pathsForIndexing.contains(path)
1792 1795
						&& leafData.trim().length() != 0) {
1793
					logMetacat.debug("paths found for indexing: " + currentName);
1796
					logMetacat.debug("DocumentImpl.traverseParents - paths found for indexing: " + currentName);
1794 1797
					pathsFoundForIndexing.put(path, new PathIndexEntry(leafNodeId,
1795 1798
							path, docid, leafParentId, leafData, leafDataNumerical));
1796 1799
				}
......
1801 1804
                if ( !path.equals("") ) {
1802 1805
                  fullPath = '/' + path;
1803 1806
                }
1804
                logMetacat.debug("C: " + fullPath +"\n");
1807
                logMetacat.debug("DocumentImpl.traverseParents - C: " + fullPath +"\n");
1805 1808
                pathList.put(fullPath, new PathIndexEntry(leafNodeId, fullPath,
1806 1809
                    docid, doctype, parentId));
1807 1810

  
1808 1811
				if (pathsForIndexing.contains(fullPath)
1809 1812
						&& leafData.trim().length() != 0) {
1810
					logMetacat.debug("paths found for indexing: " + currentName);
1813
					logMetacat.debug("DocumentImpl.traverseParents - paths found for indexing: " + currentName);
1811 1814
					pathsFoundForIndexing.put(fullPath, new PathIndexEntry(
1812 1815
							leafNodeId, fullPath, docid, leafParentId, leafData,
1813 1816
							leafDataNumerical));
......
1831 1834
    	double start = System.currentTimeMillis()/1000;
1832 1835
        String familyId = docid;
1833 1836
        String sql = "DELETE FROM xml_index WHERE docid = ?";
1834
        logMetacat.debug("DocumentImpl.deleteNodeIndex - SQL is: " + sql);
1835 1837

  
1836 1838
        PreparedStatement pstmt = conn.prepareStatement(sql);
1837 1839

  
......
1840 1842

  
1841 1843
        // Execute the delete and close the statement
1842 1844
        pstmt.setString(1, familyId);
1845
        logMetacat.debug("DocumentImpl.deleteNodeIndex - executing SQL: " + pstmt.toString());
1843 1846
        int rows = pstmt.executeUpdate();
1844 1847
        pstmt.close();
1845 1848
        logMetacat.debug("DocumentImpl.deleteNodeIndex - Deleted " + rows + " rows from xml_index " +
......
1869 1872
        pstmt = conn.prepareStatement(
1870 1873
                "DELETE FROM xml_path_index WHERE docid = ?");
1871 1874
        pstmt.setString(1, docid);
1875
        logMetacat.debug("DocumentImpl.deleteNodeIndex - executing SQL: " + pstmt.toString());
1872 1876
        rows = pstmt.executeUpdate();
1873 1877
        conn.increaseUsageCount(1);
1874 1878
        pstmt.close();
......
1905 1909
        Iterator<PathIndexEntry> it = pathList.values().iterator();
1906 1910
        while (it.hasNext()) {
1907 1911
        	 PathIndexEntry entry = (PathIndexEntry)it.next();
1908
        	 logMetacat.debug("DocumentImpl.updateNodeIndex - Inserting: " + entry.nodeId +
1909
        			 " (" + entry.parentId + "): " + entry.path);
1910 1912
        	 pstmt.setLong(1, entry.nodeId);
1911 1913
        	 pstmt.setString(2, entry.path);
1912 1914
        	 pstmt.setLong(5, entry.parentId);
1915
        	 logMetacat.debug("DocumentImpl.updateNodeIndex - executing SQL: " + pstmt.toString());
1913 1916
        	 pstmt.executeUpdate();
1914 1917
         }
1915 1918
        // Close the database statement
......
1944 1947
             pstmt.setString(2, entry.path);
1945 1948
             pstmt.setString(3, entry.nodeData);
1946 1949
             pstmt.setFloat(4, entry.nodeDataNumerical);
1947
             pstmt.setLong(5, entry.parentId);    
1950
             pstmt.setLong(5, entry.parentId);  
1951
             logMetacat.debug("DocumentImpl.updatePathIndex - executing SQL: " + pstmt.toString());
1948 1952
             pstmt.execute();
1949 1953
        }
1950 1954
        // Close the database statement
......
1965 1969
            serialNumber = dbconn.getCheckOutSerialNumber();
1966 1970
            pstmt = dbconn.prepareStatement("select rev from xml_documents "
1967 1971
                    + "where docid like '" + newid + "'");
1972
            logMetacat.debug("DocumentImpl.isRevisionOnly - executing SQL: " + pstmt.toString());
1968 1973
            pstmt.execute();
1969 1974
            ResultSet rs = pstmt.getResultSet();
1970 1975
            boolean tablehasrows = rs.next();
......
2074 2079

  
2075 2080
            pstmt = dbconn.prepareStatement(sql.toString());
2076 2081

  
2082
            logMetacat.debug("DocumentImpl.getDocumentInfo - executing SQL: " + pstmt.toString());
2077 2083
            pstmt.execute();
2078 2084
            ResultSet rs = pstmt.getResultSet();
2079 2085
            boolean tableHasRows = rs.next();
......
2097 2103
            //because connection use twice here, so we need to increase one
2098 2104
            dbconn.increaseUsageCount(1);
2099 2105
            pstmt.setInt(1, serverlocation);
2106
            logMetacat.debug("DocumentImpl.getDocumentInfo - executing SQL: " + pstmt.toString());
2100 2107
            pstmt.execute();
2101 2108
            rs = pstmt.getResultSet();
2102 2109
            tableHasRows = rs.next();
......
2122 2129
                // Bind the values to the query
2123 2130
                pstmt.setString(1, doctype);
2124 2131

  
2132
                logMetacat.debug("DocumentImpl.getDocumentInfo - executing SQL: " + pstmt.toString());
2125 2133
                pstmt.execute();
2126 2134
                rs = pstmt.getResultSet();
2127 2135
                tableHasRows = rs.next();
......
2207 2215
            // Bind the values to the query
2208 2216
            pstmt.setLong(1, rootnodeid);
2209 2217
            //System.out.println("in getNodeREcorelist !!!!!!!!!!!4");
2218
            logMetacat.debug("DocumentImpl.getNodeRecordList - executing SQL: " + pstmt.toString());
2210 2219
            pstmt.execute();
2211 2220
            ResultSet rs = pstmt.getResultSet();
2212 2221
            //System.out.println("in getNodeREcorelist !!!!!!!!!!!5");
......
2350 2359
                
2351 2360
            } else if (action.equals("UPDATE")) {
2352 2361
                int thisrev = DBUtil.getLatestRevisionInDocumentTable(docid);
2353
                logMetacat.debug("DocumentImpl.writeDocumentToDB - this revsion is: " + thisrev);
2362
                logMetacat.debug("DocumentImpl.writeDocumentToDB - this revision is: " + thisrev);
2354 2363
                // Save the old document publicaccessentry in a backup table
2355
                String accNumber = docid+PropertyService.getProperty("document.accNumSeparator")+thisrev;
2364
                String accNumber = docid + PropertyService.getProperty("document.accNumSeparator") + thisrev;
2356 2365
                thisdoc = new DocumentImpl(accNumber, false);
2357 2366
                DocumentImpl.archiveDocAndNodesRevision(connection, docid, user, thisdoc);
2358
                logMetacat.debug("DocumentImpl.writeDocumentToDB - after archiveDoc");
2359 2367
                //if the updated vesion is not greater than current one,
2360 2368
                //throw it into a exception
2361 2369
                if (rev <= thisrev) {
......
2365 2373
                    //set the user specified revision
2366 2374
                    thisrev = rev;
2367 2375
                }
2368
                logMetacat.debug("DocumentImpl.writeDocumentToDB - final revsion is: " + thisrev);
2376
                logMetacat.debug("DocumentImpl.writeDocumentToDB - final revision is: " + thisrev);
2369 2377
                boolean useXMLIndex = (new Boolean(PropertyService
2370 2378
                        .getProperty("database.usexmlindex"))).booleanValue();
2371 2379
                if (useXMLIndex) {
2372
                    logMetacat.debug("DocumentImpl.writeDocumentToDB - before delete");
2373 2380
                    double start = System.currentTimeMillis()/1000;
2374 2381
                    // Delete index for the old version of docid
2375 2382
                    // The new index is inserting on the next calls to DBSAXNode
2376 2383
                    pstmt = connection
2377 2384
                            .prepareStatement("DELETE FROM xml_index WHERE docid='"
2378 2385
                                    + this.docid + "'");
2379
                   
2386

  
2380 2387
                    // Increase dbconnection usage count
2381 2388
                    connection.increaseUsageCount(1);
2382 2389
                  
2390
                    logMetacat.debug("DocumentImpl.writeDocumentToDB - executing SQL: " + pstmt.toString());
2383 2391
                    pstmt.execute();
2384 2392
                  
2385 2393
                    pstmt.close();
2386 2394
                    double end = System.currentTimeMillis()/1000;
2387
                    logMetacat.info("DocumentImpl.writeDocumentToDB - Time for deletindex xml_index in UPDATE is "+(end -start));
2395
                    logMetacat.info("DocumentImpl.writeDocumentToDB - Time for delete xml_index in UPDATE is "+(end -start));
2388 2396
                }
2389 2397

  
2390 2398
                // Update the new document to reflect the new node tree
......
2447 2455
                }
2448 2456

  
2449 2457
            } else {
2450
                System.err.println("Action not supported: " + action);
2458
                logMetacat.error("DocumentImpl.writeDocumentToDB - Action not supported: " + action);
2451 2459
            }
2452 2460

  
2453 2461
            // Do the insertion
2454
           
2462
            logMetacat.debug("DocumentImpl.writeDocumentToDB - executing SQL: " + pstmt.toString());
2455 2463
            pstmt.execute();
2456 2464
            
2457 2465
            pstmt.close();
......
2465 2473
                pstmt.setLong(1, thisdoc.getRootNodeID());
2466 2474
                pstmt.execute();
2467 2475
                pstmt.close();*/
2468
                deleteXMLNodes(connection, thisdoc.getRootNodeID());
2476
            	logMetacat.debug("DocumentImpl.writeDocumentToDB - Deleting xml nodes for docid: " + 
2477
            			thisdoc.getDocID() + " using root node ID: " + thisdoc.getRootNodeID());
2478
            	deleteXMLNodes(connection, thisdoc.getRootNodeID());
2469 2479
            }
2470 2480

  
2471 2481
        } catch (SQLException sqle) {
2482
        	logMetacat.error("DocumentImpl.writeDocumentToDB - SQL error: " + sqle.getMessage());
2472 2483
            sqle.printStackTrace();
2473 2484
            throw sqle;
2474 2485
        } catch (Exception e) {
2486
        	logMetacat.error("DocumentImpl.writeDocumentToDB - General error: " + e.getMessage());
2475 2487
            e.printStackTrace();
2476 2488
            throw e;
2477 2489
        }
......
3068 3080
            //bind variable
3069 3081
            pstate.setString(1, docid);
3070 3082
            //excute query
3083
            logMetacat.debug("DocumentImpl.getDocTypeFromDBForCurrentDocument - executing SQL: " + pstate.toString());
3071 3084
            pstate.execute();
3072 3085
            //handle resultset
3073 3086
            rs = pstate.getResultSet();
......
3121 3134
            pstmt = conn.prepareStatement("SELECT * FROM xml_documents "
3122 3135
                                          + "WHERE docid = ?");
3123 3136
            pstmt.setString(1, docid);
3137
            logMetacat.debug("DocumentImpl.delete - executing SQL: " + pstmt.toString());
3124 3138
            pstmt.execute();
3125 3139
            ResultSet rs = pstmt.getResultSet();
3126 3140
            if(!rs.next()){
......
3169 3183
            pstmt = conn
3170 3184
                    .prepareStatement("DELETE FROM xml_index WHERE docid = ?");
3171 3185
            pstmt.setString(1, docid);
3186
            logMetacat.debug("DocumentImpl.delete - executing SQL: " + pstmt.toString());
3172 3187
            pstmt.execute();
3173 3188
            pstmt.close();
3174 3189
            conn.increaseUsageCount(1);
......
3179 3194
            pstmt = conn.prepareStatement(
3180 3195
                    "DELETE FROM xml_access WHERE accessfileid = ?");
3181 3196
            pstmt.setString(1, docid);
3182
            logMetacat.debug("DocumentImpl.delete - running sql: " + pstmt.toString());
3197
            logMetacat.debug("DocumentImpl.delete - executing SQL: " + pstmt.toString());
3183 3198
            pstmt.execute();
3184 3199
            pstmt.close();
3185 3200
            conn.increaseUsageCount(1);
......
3188 3203
            pstmt = conn.prepareStatement(
3189 3204
                    "DELETE FROM xml_access WHERE docid = ?");
3190 3205
            pstmt.setString(1, docid);
3191
            logMetacat.debug("DocumentImpl.delete - running sql: " + pstmt.toString());
3206
            logMetacat.debug("DocumentImpl.delete - executing SQL: " + pstmt.toString());
3192 3207
            pstmt.execute();
3193 3208
            pstmt.close();
3194 3209
            conn.increaseUsageCount(1);
......
3285 3300
         	   DBQuery.clearQueryResultCache();
3286 3301
            }
3287 3302
           double end = System.currentTimeMillis()/1000;
3288
           logMetacat.info("DocumentImpl.delete - total delete time is ===== "+(end - start));
3303
           logMetacat.info("DocumentImpl.delete - total delete time is:  " + (end - start));
3289 3304

  
3290 3305
        } catch (Exception e) {
3291 3306
            logMetacat.error("DocumentImpl.delete - General error: " + e.getMessage());
......
3571 3586
        pstmt.setString(1, docid);
3572 3587
        pstmt.setString(2, user);
3573 3588
        pstmt.setString(3, docid);
3589
        logMetacat.debug("DocumentImpl.archiveDocAndNodesRevison - executing SQL: " + pstmt.toString());
3574 3590
        pstmt.execute();
3575 3591
        pstmt.close();
3576 3592
        double end = System.currentTimeMillis()/1000;
......
3618 3634
        dbconn.increaseUsageCount(1);
3619 3635
        // Bind the values to the query and execute it
3620 3636
        pstmt.setLong(1, rootNodeId);
3637
        logMetacat.debug("DocumentImpl.moveNodesToNodesRevision - executing SQL: " + pstmt.toString());
3621 3638
        pstmt.execute();
3622 3639
        pstmt.close();
3623 3640
        double end = System.currentTimeMillis()/1000;
......
3651 3668
            pstmt.setString(1, docid);
3652 3669
            pstmt.setString(2, user);
3653 3670
            pstmt.setString(3, docid);
3671
            logMetacat.debug("DocumentImpl.archiveDocRevision - executing SQL: " + pstmt.toString());
3654 3672
            pstmt.execute();
3655 3673
            pstmt.close();
3656 3674
        } catch (SQLException e) {
......
3687 3705
            //delete a record
3688 3706
            pStmt = conn.prepareStatement(
3689 3707
                    "DELETE FROM xml_documents WHERE docid = '" + docId + "'");
3708
            logMetacat.debug("DocumentImpl.deleteXMLDocuments - executing SQL: " + pStmt.toString());
3690 3709
            pStmt.execute();
3691 3710
        } finally {
3692 3711
            try {
......
3876 3895
                                + ", '" + replicate + "', '" + dataReplicate
3877 3896
                                + "','" + hub + "')");
3878 3897

  
3898
                logMetacat.debug("DocumentImpl.insertServerIntoReplicationTable - executing SQL: " + pStmt.toString());
3879 3899
                pStmt.execute();
3880 3900
                dbConn.commit();
3881 3901
                // Increase usage number
......
4155 4175
              }
4156 4176
            }
4157 4177
            // Do the insertion
4178
            logMetacat.debug("DocumentImpl.writeDocumentToRevisionTable - executing SQL: " + pstmt.toString());
4158 4179
            pstmt.execute();
4159 4180
            pstmt.close();
4160 4181
            logMetacat.debug("DocumentImpl.writeDocumentToRevisionTable - end of write into revisons");
......
4162 4183
        } 
4163 4184
        catch (SQLException sqle) 
4164 4185
        {
4186
        	logMetacat.error("DocumentImpl.writeDocumentToRevisionTable - SQL error: " + sqle.getMessage());
4165 4187
        	sqle.printStackTrace();
4166 4188
            throw sqle;
4167 4189
        } 
4168 4190
        catch (Exception e) 
4169 4191
        {
4192
        	logMetacat.error("DocumentImpl.writeDocumentToRevisionTable - General error: " + e.getMessage());
4170 4193
            e.printStackTrace();
4171 4194
            throw e;
4172 4195
        }
......
4219 4242
    static private void deleteXMLNodes(DBConnection dbconn, long rootId) throws Exception
4220 4243
    {
4221 4244
//        AccessionNumber ac;
4245
    	logMetacat.debug("DocumentImpl.deleteXMLNodes - for root Id: " + rootId);
4222 4246
        PreparedStatement pstmt = null;
4223 4247
        double start = System.currentTimeMillis()/1000;
4224 4248
        String sql = "DELETE FROM xml_nodes WHERE rootnodeid ="+ rootId;
4225 4249
        pstmt = dbconn.prepareStatement(sql);
4226 4250
        // Increase dbconnection usage count
4227 4251
        dbconn.increaseUsageCount(1);
4252
        logMetacat.debug("DocumentImpl.deleteXMLNodes - executing SQL: " + pstmt.toString());
4228 4253
        pstmt.execute();
4229 4254
        pstmt.close(); 
4230 4255
        double end = System.currentTimeMillis()/1000;

Also available in: Unified diff