dinsdag 18 september 2012

ADF BC: Logging to the essentials

Challenge

You want to be able to see all the sql-statements and DML-statements that your ADF application is executing.  But in contrast to the previous blog, I only want to see the statements themselves, not clutter information.

Context

JDeveloper & ADF : 11.1.1.5.0
OS: Windows 7

Solution

In this previous blog, we examined already different options.  Here we will focus on the using the base classes for ADF BC to render the information we need.
To get this working, we only 2 base classes : the EntityImpl and ViewObjectImpl base class.

Here is the code for the EntityImpl class:
package be.contribute.demo.model.framework;

import java.util.ArrayList;
import java.util.List;

import oracle.adf.share.logging.ADFLogger;

import oracle.jbo.server.AttributeDefImpl;
import oracle.jbo.server.EntityImpl;

import org.apache.commons.lang.StringUtils;


public class BaseEntityImpl extends EntityImpl {
    protected static final ADFLogger LOGGER =
        ADFLogger.createADFLogger(BaseEntityImpl.class);


    /**
     * Overwriting the buildDMLStatement to be able to show the dml statement in the logging.
     * Only in DEBUG mode, the logging will be activated
     * @param i
     * @param attributeDefImpl
     * @param attributeDefImpl2
     * @param attributeDefImpl3
     * @param b
     * @return
     * @writer Filip Huysmans
     */
    @Override
    protected StringBuffer buildDMLStatement(int i,
                                             AttributeDefImpl[] attributeDefImpl,
                                             AttributeDefImpl[] attributeDefImpl2,
                                             AttributeDefImpl[] attributeDefImpl3,
                                             boolean b) {
        StringBuffer returnValue =
            super.buildDMLStatement(i, attributeDefImpl, attributeDefImpl2,
                                    attributeDefImpl3, b);
        if (LOGGER.isFinest()) {
            loggingDML(returnValue, attributeDefImpl);
        }
        return returnValue;
    }

    /**
     * This method will call sub methods to gather the necessary information to show
     * the logging.  Depnding on the type of dml a different method is called.
     * This method will actually show the parsed statement in the logging
     * @param dmlStatement
     * @param attributeDefImpl
     * @writer Filip Huysmans
     */
    private void loggingDML(StringBuffer dmlStatement,
                            AttributeDefImpl[] attributeDefImpl) {
        if (dmlStatement != null) {
            String logDMLStatement = dmlStatement.toString();
            if (logDMLStatement.startsWith("INSERT")) {
                logDMLStatement =
                        loggingINSERT(dmlStatement, attributeDefImpl);
            } else if (logDMLStatement.startsWith("UPDATE")) {
                logDMLStatement =
                        loggingUPDATE(dmlStatement, attributeDefImpl);
            } else if (logDMLStatement.startsWith("DELETE")) {
                logDMLStatement =
                        loggingDELETE(dmlStatement, attributeDefImpl);
            }

            LOGGER.finest("Doing DML : " + logDMLStatement);
        } else {
            LOGGER.finest("DML statement was NULL");
        }
    }

    /**
     * This inner class is used to store information needed for the logging
     * @writer Filip Huysmans
     */
    private class LoggingInfo {
        private final String columnName;
        private String bindParam;
        private Object value;

        public LoggingInfo(String columnName) {
            this.columnName = columnName;
        }

        public LoggingInfo(String columnName, String bindParam) {
            this.columnName = columnName;
            this.bindParam = bindParam;
        }

        public void setBindParam(String bindParam) {
            this.bindParam = bindParam;
        }

        public void setValue(Object value) {
            this.value = value;
        }

        public String getColumnName() {
            return this.columnName;
        }

        public String getBindParam() {
            return this.bindParam;
        }

        public Object getValue() {
            return this.value;
        }
    }

    /**
     * This method will search for each of the entries of the list, the values
     * for the attributes.  This value will then be added to the LoggingInfo object.
     * @param list List with LoggingInfo objects where the columnName is already filled in
     * @param attributeDefImpl
     * @return List with LoggingInfo objects containing the columnName and values
     * @writer Filip Huysmans
     */
    private List searchValues(List list,
                                           AttributeDefImpl[] attributeDefImpl) {
        // For each of the columns search the value and replace the bind param with this value
        if (list != null && !list.isEmpty()) {
            for (LoggingInfo li : list) {
                // Find the attribute that correspond to this attribute
                if (attributeDefImpl != null && attributeDefImpl.length > 0) {
                    for (int k = 0; k < attributeDefImpl.length; k++) {
                        AttributeDefImpl attribute = attributeDefImpl[k];
                        String attributeColumnName =
                            attribute.getColumnNameForQuery();
                        attributeColumnName =
                                StringUtils.split(attributeColumnName, ".")[1];
                        if (attributeColumnName.equals(li.getColumnName())) {
                            // This is the correct attribute; find the value
                            li.setValue(getAttributeInternal(attribute.getName()));
                        }
                    }
                }
            }
        }
        return list;
    }

    /**
     * This method will replace the bind parameters (like :1) with the corresponding value.
     * The necessary information is gathered from the list parameter.
     * @param list List of LoggingInfo objects containing bindParameter and Value objects
     * @param dmlStatement The string of the statement with the bind parameters intact
     * @return String of the statement with the bind parameters replaced by their values
     * @writer Filip Huysmans
     */
    private String replaceBindParamsWithValue(List list,
                                              String dmlStatement) {
        String returnValue = dmlStatement;
        if (list != null) {
            for (LoggingInfo li : list) {
                // Replacing the bind param with the actual value
                returnValue =
                        StringUtils.replace(returnValue, // The current log statement
                            li.getBindParam(), // The bind param like ':1'
                            li.getValue() != null ? li.getValue().toString() :
                            "null"); // The string representation of the value
            }
        }
        return returnValue;
    }

    /**
     * This method will add the necessary LoggingInfo objects based upon the columnsString.
     *
     * @param columnsString This string must be a sequence of  = , seperated by the seperator.  Ex: "id=:2, name=:5" or "id=:2 AND name=:5"
     * @param list Existing list of LoggingInfo objects
     * @param seperator The seperator that seperateds the different instances of columns in the columnsString
     * @return List of LoggingInfo objects based upon the columnsString and the already existing list
     * @writer Filip Huysmans
     */
    private List addColumnsToList(String columnsString,
                                               List list,
                                               String seperator) {
        String[] setListOfColumns = columnsString.split(seperator);
        if (setListOfColumns != null && setListOfColumns.length > 0) {
            for (int i = 0; i < setListOfColumns.length; i++) {
                String[] column = setListOfColumns[i].split("=");
                list.add(new LoggingInfo(column[0], column[1]));
            }
        }
        return list;
    }

    /**
     * This method is used in the case of an INSERT statement.
     * @param dmlStatement
     * @param attributeDefImpl
     * @return
     * @writer Filip Huysmans
     */
    private String loggingINSERT(StringBuffer dmlStatement,
                                 AttributeDefImpl[] attributeDefImpl) {
        String returnValue = dmlStatement.toString();
        List list = new ArrayList();
        // Getting the list of columns
        String attributeListString =
            dmlStatement.substring(dmlStatement.indexOf("(") + 1,
                                   dmlStatement.indexOf(")"));
        String[] attributeList = attributeListString.split(",");
        // Getting the list of values
        String attributeBindVarListString =
            dmlStatement.substring(dmlStatement.indexOf("(",
                                                        dmlStatement.indexOf("(") +
                                                        1) + 1,
                                   dmlStatement.indexOf(")",
                                                        dmlStatement.indexOf(")") +
                                                        1));
        String[] attributeBindVarList = attributeBindVarListString.split(",");
        // Adding the columns to the list
        if (attributeList != null && attributeList.length > 0) {
            for (int i = 0; i < attributeList.length; i++) {
                list.add(new LoggingInfo(attributeList[i],
                                         attributeBindVarList[i]));
            }
        }
        // Searching the values
        list = searchValues(list, attributeDefImpl);

        // Replacing the bind params with the values
        returnValue = replaceBindParamsWithValue(list, returnValue);

        return returnValue;
    }

    /**
     * This method is used in case of an UPDATE statement.
     * @param dmlStatement
     * @param attributeDefImpl
     * @return
     * @writer Filip Huysmans
     */
    private String loggingUPDATE(StringBuffer dmlStatement,
                                 AttributeDefImpl[] attributeDefImpl) {
        String returnValue = dmlStatement.toString();
        List list = new ArrayList();
        // Getting the list of columns
        String setListString =
            dmlStatement.substring(dmlStatement.indexOf("SET ") + 4,
                                   dmlStatement.indexOf(" WHERE "));
        list = addColumnsToList(setListString, list, ",");
        // Do the same for the where clause
        String whereListString =
            dmlStatement.substring(dmlStatement.indexOf(" WHERE ") + 7);
        list = addColumnsToList(whereListString, list, " AND ");
        // Searching the values
        list = searchValues(list, attributeDefImpl);
        // Replacing the bind params with the values
        returnValue = replaceBindParamsWithValue(list, returnValue);
        // Return the parsed statement
        return returnValue;
    }

    /**
     * This method is used in case of a DELETE statement.
     * @param dmlStatement
     * @param attributeDefImpl
     * @return
     * @writer Filip Huysmans
     */
    private String loggingDELETE(StringBuffer dmlStatement,
                                 AttributeDefImpl[] attributeDefImpl) {
        String returnValue = dmlStatement.toString();
        List list = new ArrayList();
        // Getting the columns of the where clause
        String whereListString =
            dmlStatement.substring(dmlStatement.indexOf(" WHERE ") + 7);
        String[] whereListOfColumns = whereListString.split(" AND ");
        if (whereListOfColumns != null && whereListOfColumns.length > 0) {
            for (int i = 0; i < whereListOfColumns.length; i++) {
                String[] column = whereListOfColumns[i].split("=");
                list.add(new LoggingInfo(column[0], column[1]));
            }
        }
        // Searching the values
        list = searchValues(list, attributeDefImpl);
        // Replacing the bind params with the values
        returnValue = replaceBindParamsWithValue(list, returnValue);
        // Returning the parsed statement
        return returnValue;
    }

    /**
     * This method will parse a statment with '?' by the list of objects
     * This can be used to log custom preparedStatements.
     * @param statement Ex: select id from table where id = ?
     * @param objects List of objects to put in place of the ?.  The order must be the same as the order of the ?
     * @writer Filip Huysmans
     */
    public void logDynamicStatements(String statement, Object... objects) {
        String toLog = statement;
        for (Object o : objects) {
            if (o == null) {
                // When the object is null, replace the ? by the word null
                toLog = toLog.replaceFirst("\\?", "null");
            } else {
                toLog = toLog.replaceFirst("\\?", o.toString());
            }
        }
        LOGGER.finest(toLog);
    }
}

If you see a bizarre line 309, please ignore it!!

Here is the code for the ViewObjectImpl class:
package be.contribute.demo.model.framework;


import oracle.adf.share.logging.ADFLogger;

import oracle.jbo.AttributeList;
import oracle.jbo.Variable;
import oracle.jbo.VariableValueManager;
import oracle.jbo.server.ViewObjectImpl;


public class BaseViewObjectImpl extends ViewObjectImpl {
    protected static final ADFLogger LOGGER =
        ADFLogger.createADFLogger(BaseViewObjectImpl.class);


    /**
     * Overriding the executeQuery method for debug reasons.
     * Each time a query is executed on a view, we show the query,
     * the value of the bind variables and the number of result records
     * @writer Filip Huysmans
     */
    @Override
    public void executeQuery() {
        long start = 0;
        if (LOGGER.isFinest()) {
            showQueryMetadata();
            start = System.currentTimeMillis();
        }

        // Executing the query
        super.executeQuery();
        if (LOGGER.isFinest()) {
            showQueryStatistics(System.currentTimeMillis() - start);
        }
    }

    @Override
    protected void executeQueryForCollection(Object object, Object[] object2,
                                             int i) {
        long start = 0;
        if (LOGGER.isFinest()) {
            showQueryMetadata();
            start = System.currentTimeMillis();
        }

        // Executing the query
        super.executeQueryForCollection(object, object2, i);
        if (LOGGER.isFinest()) {
            showQueryStatistics(System.currentTimeMillis() - start);
        }
    }

    private void showQueryStatistics(long paQueryTime) {
        LOGGER.finest("Query time (ms) : " + paQueryTime);
        // Showing the number of records
        LOGGER.finest("Nbr results : " + getAllRowsInRange().length);
        LOGGER.finest("End ExecuteQuery for " + getClass().getName());
    }

    private void showQueryMetadata() {
        LOGGER.finest("Start ExecuteQuery for " + getClass().getName());
        // Showing the query
        LOGGER.finest("query : " + getQuery());
        // Showing the bind variables
        getParametersAsStorageTypes();
        // Getting the bind variables
        AttributeList attributeList = getNamedWhereClauseParams();
        String[] attributeNames = attributeList.getAttributeNames();
        if (attributeNames == null || attributeNames.length == 0) {
            LOGGER.finest("No bind variables found");
        } else {
            for (int i = 0; i < attributeNames.length; i++) {
                LOGGER.finest("Bind variable : " + attributeNames[i] +
                              " - Value : " + attributeList.getAttribute(i));
            }
        }
    }

    @Override
    public VariableValueManager ensureVariableManager() {
        // TODO Called too many times but restricting execution seems to cripple the functionality.
        VariableValueManager evm = super.ensureVariableManager();
        Variable[] variable = evm.getVariables();
        if (variable != null) {
            for (int i = 0; i < variable.length; i++) {
                String name = variable[i].getName();

                Object value = evm.getVariableValue(name);

                if (value != null && (value instanceof String) &&
                    ((String)value).contains("*")) {
                    evm.setVariableValue(name,
                                         ((String)value).replaceAll("\\*",
                                                                    "%"));

                }
            }
        }
        return evm;
    }

    /**
     * Overriding this method to allow for more complete debug info.
     * @return
     * @writer Filip Huysmans
     */
    @Override
    public Object[] getParametersAsStorageTypes() {
        Object[] object = super.getParametersAsStorageTypes();
        if (object != null) {
            for (int i = 0; i < object.length; i++) {
                Object[] parameter = (Object[])object[i];
                LOGGER.finest("VIEWLINK bindparameter for " + getName() +
                              " : " + parameter[0] + " = " + parameter[1]);
            }
        }
        return object;
    }

}


After creating these java classes, you need to register them within JDeveloper or your project.






Now when you run the application, you would not see the message immediately because we are using the ADFLogger.  Per default no logging is done for our custom classes.  To activate it, just have a look at this previous blog and activate the logging for our base classes.
Now you will get an output like this one:
<BaseViewObjectImpl> <showQueryMetadata> Start ExecuteQuery for ac.spaces.portal.app.model.vo.DepartmentsViewImpl
<BaseViewObjectImpl> <showQueryMetadata> query : SELECT Departments.DEPARTMENT_ID,         Departments.DEPARTMENT_NAME,         Departments.MANAGER_ID,         Departments.LOCATION_ID,         Departments.COST_CENTER,         Employees.FIRST_NAME,         Employees.EMPLOYEE_ID,         Employees.LAST_NAME,         (select 'a' from dual) AS stupid FROM DEPARTMENTS Departments, EMPLOYEES Employees WHERE Departments.MANAGER_ID = Employees.EMPLOYEE_ID
<BaseViewObjectImpl> <showQueryMetadata> No bind variables found
<BaseViewObjectImpl> <showQueryStatistics> Query time (ms) : 3
<BaseViewObjectImpl> <showQueryStatistics> Nbr results : 13
<BaseViewObjectImpl> <showQueryStatistics> End ExecuteQuery for ac.spaces.portal.app.model.vo.DepartmentsViewImpl
<BaseEntityImpl> <loggingDML> Doing DML : INSERT INTO DEPARTMENTS(DEPARTMENT_ID,DEPARTMENT_NAME,MANAGER_ID,LOCATION_ID) VALUES (4,Filip Dept,100,1000)
<BaseEntityImpl> <loggingDML> Doing DML : UPDATE DEPARTMENTS Departments SET LOCATION_ID=null WHERE DEPARTMENT_ID=4
<BaseEntityImpl> <loggingDML> Doing DML : DELETE FROM DEPARTMENTS Departments WHERE DEPARTMENT_ID=4

1 opmerking:

  1. Invest in Ripple on eToro the World's Leading Social Trading Network...

    Join millions who have already found easier methods for investing in Ripple...

    Learn from experienced eToro traders or copy their positions automatically.

    BeantwoordenVerwijderen