--- src/java/org/apache/poi/hssf/usermodel/HSSFSheet.java (revision 1368395) +++ src/java/org/apache/poi/hssf/usermodel/HSSFSheet.java (working copy) @@ -144,9 +144,10 @@ Iterator iter = sheet.getCellValueIterator(); long timestart = System.currentTimeMillis(); - if (log.check( POILogger.DEBUG )) + if (log.check( POILogger.DEBUG )) { log.log(DEBUG, "Time at start of cell creating in HSSF sheet = ", Long.valueOf(timestart)); + } HSSFRow lastrow = null; // Add every cell to its row @@ -172,18 +173,25 @@ hrow = createRowFromRecord(rowRec); } } - if (log.check( POILogger.DEBUG )) + if (log.check( POILogger.DEBUG )) { + if (cval instanceof Record) { log.log( DEBUG, "record id = " + Integer.toHexString( ( (Record) cval ).getSid() ) ); + } else { + log.log( DEBUG, "record = " + cval ); + } + } hrow.createCellFromRecord( cval ); - if (log.check( POILogger.DEBUG )) + if (log.check( POILogger.DEBUG )) { log.log( DEBUG, "record took ", Long.valueOf( System.currentTimeMillis() - cellstart ) ); + } } - if (log.check( POILogger.DEBUG )) + if (log.check( POILogger.DEBUG )) { log.log(DEBUG, "total sheet cell creation took ", Long.valueOf(System.currentTimeMillis() - timestart)); } + } /** * Create a new row within the sheet and return the high level representation --- src/java/org/apache/poi/ss/formula/WorkbookEvaluator.java (revision 1368395) +++ src/java/org/apache/poi/ss/formula/WorkbookEvaluator.java (working copy) @@ -70,6 +70,7 @@ * For POI internal use only * * @author Josh Micich + * @author Thies Wellpott (debug output enhancements) */ public final class WorkbookEvaluator { @@ -384,14 +385,50 @@ } throw new RuntimeException("Unexpected cell type (" + cellType + ")"); } + + + /** + * Perform detailed output of formular evaluation for next evaluation only? + * Is for developer use only (also developers using POI for their XLS files). + * Log-Level WARN is for basic infos, INFO for detailed information. These quite + * high levels are used because you have to explicitly enable this specific logging. + */ + public static boolean dbgEvaluationOutputForNextEval = false; + + // special logger for formula evaluation output (because of possibly very large output) + private static final POILogger EVAL_LOG = POILogFactory.getLogger("POI.FormulaEval"); + // current indent level for evalution; negative value for no output + private int dbgEvaluationOutputIndent = -1; + // visibility raised for testing /* package */ ValueEval evaluateFormula(OperationEvaluationContext ec, Ptg[] ptgs) { + String dbgIndentStr = ""; // always init. to non-null just for defensive avoiding NPE + if (dbgEvaluationOutputForNextEval) { + // first evaluation call when ouput is desired, so iit. this evaluator instance + dbgEvaluationOutputIndent = 1; + dbgEvaluationOutputForNextEval = false; + } + if (dbgEvaluationOutputIndent > 0) { + // init. indent string to needed spaces (create as substring vom very long space-only string; + // limit indendation for deep recursions) + dbgIndentStr = " "; + dbgIndentStr = dbgIndentStr.substring(0, Math.min(dbgIndentStr.length(), dbgEvaluationOutputIndent*2)); + EVAL_LOG.log(POILogger.WARN, dbgIndentStr + + "- evaluateFormula('" + ec.getRefEvaluatorForCurrentSheet().getSheetName() + + "'/" + new CellReference(ec.getRowIndex(), ec.getColumnIndex()).formatAsString() + + "): " + Arrays.toString(ptgs).replaceAll("\\Qorg.apache.poi.ss.formula.ptg.\\E", "")); + dbgEvaluationOutputIndent++; + } + Stack stack = new Stack(); for (int i = 0, iSize = ptgs.length; i < iSize; i++) { // since we don't know how to handle these yet :( Ptg ptg = ptgs[i]; + if (dbgEvaluationOutputIndent > 0) { + EVAL_LOG.log(POILogger.INFO, dbgIndentStr + " * ptg " + i + ": " + ptg); + } if (ptg instanceof AttrPtg) { AttrPtg attrPtg = (AttrPtg) ptg; if (attrPtg.isSum()) { @@ -497,13 +534,28 @@ } // logDebug("push " + opResult); stack.push(opResult); + if (dbgEvaluationOutputIndent > 0) { + EVAL_LOG.log(POILogger.INFO, dbgIndentStr + " = " + opResult); + } } ValueEval value = stack.pop(); if (!stack.isEmpty()) { throw new IllegalStateException("evaluation stack not empty"); } - return dereferenceResult(value, ec.getRowIndex(), ec.getColumnIndex()); + ValueEval result = dereferenceResult(value, ec.getRowIndex(), ec.getColumnIndex()); + if (dbgEvaluationOutputIndent > 0) { + EVAL_LOG.log(POILogger.INFO, dbgIndentStr + "finshed eval of " + + new CellReference(ec.getRowIndex(), ec.getColumnIndex()).formatAsString() + + ": " + result); + dbgEvaluationOutputIndent--; + if (dbgEvaluationOutputIndent == 1) { + // this evaluation is done, reset indent to stop logging + dbgEvaluationOutputIndent = -1; + } + } // if + return result; + } /** --- src/java/org/apache/poi/util/SystemOutLogger.java (revision 1368395) +++ src/java/org/apache/poi/util/SystemOutLogger.java (working copy) @@ -33,6 +33,7 @@ { private String _cat; + @Override public void initialize(final String cat) { this._cat=cat; @@ -45,6 +46,7 @@ * @param obj1 The object to log. */ + @Override public void log(final int level, final Object obj1) { log(level, obj1, null); @@ -57,11 +59,12 @@ * @param obj1 The object to log. This is converted to a string. * @param exception An exception to be logged */ + @Override public void log(final int level, final Object obj1, final Throwable exception) { if (check(level)) { - System.out.println("["+_cat+"] "+obj1); - if(exception != null) { + System.out.println("[" + _cat + "]" + LEVEL_STRINGS_SHORT[Math.min(LEVEL_STRINGS_SHORT.length-1, level)] + " " + obj1); + if (exception != null) { exception.printStackTrace(System.out); } } @@ -77,6 +80,7 @@ * @see #ERROR * @see #FATAL */ + @Override public boolean check(final int level) { int currentLevel; --- src/java/org/apache/poi/util/POILogger.java (revision 1368395) +++ src/java/org/apache/poi/util/POILogger.java (working copy) @@ -17,7 +17,8 @@ package org.apache.poi.util; -import java.util.*; +import java.util.ArrayList; +import java.util.List; /** * A logger interface that strives to make it as easy as possible for @@ -31,12 +32,18 @@ */ public abstract class POILogger { - public static int DEBUG = 1; - public static int INFO = 3; - public static int WARN = 5; - public static int ERROR = 7; - public static int FATAL = 9; + public static final int DEBUG = 1; + public static final int INFO = 3; + public static final int WARN = 5; + public static final int ERROR = 7; + public static final int FATAL = 9; + /** Short strings for numeric log level. Use level as array index. */ + protected static final String LEVEL_STRINGS_SHORT[] = {"?", "D", "?", "I", "?", "W", "?", "E", "?", "F", "?"}; + /** Long strings for numeric log level. Use level as array index. */ + protected static final String LEVEL_STRINGS[] = {"?0?", "DEBUG", "?2?", "INFO", "?4?", "WARN", "?6?", "ERROR", "?8?", "FATAL", "?10+?"}; + + /** * package scope so it cannot be instantiated outside of the util * package. You need a POILogger? Go to the POILogFactory for one --- src/documentation/content/xdocs/spreadsheet/eval.xml (revision 1368395) +++ src/documentation/content/xdocs/spreadsheet/eval.xml (working copy) @@ -42,7 +42,7 @@
Status

The code currently provides implementations for all the arithmatic operators. It also provides implementations for approx. 140 built in - functions in Excel. The framework however makes is easy to add + functions in Excel. The framework however makes it easy to add implementation of new functions. See the Formula evaluation development guide and javadocs for details.

@@ -249,7 +249,7 @@ existing workbooks with formulas. This can be done in two ways:

- 1. Re-evaluate formuals with POI's FormulaEvaluator: + 1. Re-evaluate formulas with POI's FormulaEvaluator:

Workbook wb = WorkbookFactory.create(new FileInputStream("workbook.xls")); @@ -308,5 +308,34 @@
+
Formula Evaluation Debugging +

POI is not perfect and you may stumble across formula evaluation problems (Java exceptions + or just different results) in your special use case. To support an easy detailed analysis, a special + logging of the full evaluation is provided.

+

The output of this logging may be very large (depends on your EXCEL), so this logging has to be explicitly enabled + for each single formula evaluation. The implementation is not thread safe (uses a single static variable + as logging indicator for easy use), but should not be used in production anyway - only for specific development use.

+

Example use:

+ + // activate logging to console + System.setProperty("org.apache.poi.util.POILogger", "org.apache.poi.util.SystemOutLogger"); + System.setProperty("poi.log.level", POILogger.INFO + ""); + + // open your file + Workbook wb = new HSSFWorkbook(new FileInputStream("foobar.xls")); + FormulaEvaluator evaluator = wb.getCreationHelper().createFormulaEvaluator(); + + // get your cell + Cell cell = wb.getSheet(0).getRow(0).getCell(0); // just a dummy example + + // perform debug output for the next evaluate-call only + WorkbookEvaluator.dbgEvaluationOutputForNextEval = true; + evaluator.evaluateFormulaCell(cell); + evaluator.evaluateFormulaCell(cell); // no logging performed for this next evaluate-call + +

The special Logger called "POI.FormulaEval" is used (useful if you use the CommonsLogger and a detailed logging configuration). + The used log levels are WARN and INFO (for detailed parameter info and results) - the level are so high to allow this + special logging without beeing disturbed by the bunch of DEBUG log entries from other classes.

+