Attachment #29152 for bug #53642

View | Details | Raw Unified | Return to bug 53642
Collapse All | Expand All




        Iterator<CellValueRecordInterface> iter = sheet.getCellValueIterator();
        long timestart = System.currentTimeMillis();

        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

                    hrow = createRowFromRecord(rowRec);
                }
            }
            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 )) {
                log.log( DEBUG, "record took ",
                    Long.valueOf( System.currentTimeMillis() - cellstart ) );
			}

        }
        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




 * For POI internal use only
 *
 * @author Josh Micich
 * @author Thies Wellpott (debug output enhancements)
 */
public final class WorkbookEvaluator {
	

		}
		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<ValueEval> stack = new Stack<ValueEval>();
		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()) {

			}
//			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");
		}
		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;

	}

	/**




{
    private String _cat;

    @Override
    public void initialize(final String cat)
    {
       this._cat=cat;

     * @param obj1 The object to log.
     */

    @Override
    public void log(final int level, final Object obj1)
    {
    	log(level, obj1, null);

     * @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 + "]" + LEVEL_STRINGS_SHORT[Math.min(LEVEL_STRINGS_SHORT.length-1, level)] + " " + obj1);
            if (exception != null) {
            	exception.printStackTrace(System.out);
            }
        }

     * @see #ERROR
     * @see #FATAL
     */
    @Override
    public boolean check(final int level)
    {
        int currentLevel;





package org.apache.poi.util;

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

/**
 * A logger interface that strives to make it as easy as possible for

 */
public abstract class POILogger {

    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




		<section><title>Status</title>
			<p>	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 it easy to add 
			 	implementation of new functions. See the <link href="eval-devguide.html"> Formula
        evaluation development guide</link>  and <link href="../apidocs/org/apache/poi/hssf/record/formula/functions/package-summary.html">javadocs</link> 
        for details. </p>

        existing workbooks with formulas. This can be done in two ways:  
      </p>   
      <p>
        1. Re-evaluate  formulas with POI's FormulaEvaluator:
      </p>   
        <source>
  Workbook wb = WorkbookFactory.create(new FileInputStream("workbook.xls"));

        </li>
      </ul>
    </section>
    <section><title>Formula Evaluation Debugging</title>
		<p>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.</p>
		<p>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.</p>
		<p>Example use:</p>
		<source>
	// 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
		</source>
		<p>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.</p>
	</section>
  </body>
</document>

Return to bug 53642

Lines 70-75 Link Here

(-)src/java/org/apache/poi/ss/formula/WorkbookEvaluator.java (-1 / +53 lines)
70	* For POI internal use only	70	* For POI internal use only
71	*	71	*
72	* @author Josh Micich	72	* @author Josh Micich
		73	* @author Thies Wellpott (debug output enhancements)
73	*/	74	*/
74	public final class WorkbookEvaluator {	75	public final class WorkbookEvaluator {
75		76
Lines 384-397 Link Here
384	}	385	}
385	throw new RuntimeException("Unexpected cell type (" + cellType + ")");	386	throw new RuntimeException("Unexpected cell type (" + cellType + ")");
386	}	387	}
		388
		389
		390	/**
		391	* Perform detailed output of formular evaluation for next evaluation only?
		392	* Is for developer use only (also developers using POI for their XLS files).
		393	* Log-Level WARN is for basic infos, INFO for detailed information. These quite
		394	* high levels are used because you have to explicitly enable this specific logging.
		395	*/
		396	public static boolean dbgEvaluationOutputForNextEval = false;
		397
		398	// special logger for formula evaluation output (because of possibly very large output)
		399	private static final POILogger EVAL_LOG = POILogFactory.getLogger("POI.FormulaEval");
		400	// current indent level for evalution; negative value for no output
		401	private int dbgEvaluationOutputIndent = -1;
		402
387	// visibility raised for testing	403	// visibility raised for testing
388	/* package */ ValueEval evaluateFormula(OperationEvaluationContext ec, Ptg[] ptgs) {	404	/* package */ ValueEval evaluateFormula(OperationEvaluationContext ec, Ptg[] ptgs) {
389		405
		406	String dbgIndentStr = ""; // always init. to non-null just for defensive avoiding NPE
		407	if (dbgEvaluationOutputForNextEval) {
		408	// first evaluation call when ouput is desired, so iit. this evaluator instance
		409	dbgEvaluationOutputIndent = 1;
		410	dbgEvaluationOutputForNextEval = false;
		411	}
		412	if (dbgEvaluationOutputIndent > 0) {
		413	// init. indent string to needed spaces (create as substring vom very long space-only string;
		414	// limit indendation for deep recursions)
		415	dbgIndentStr = " ";
		416	dbgIndentStr = dbgIndentStr.substring(0, Math.min(dbgIndentStr.length(), dbgEvaluationOutputIndent*2));
		417	EVAL_LOG.log(POILogger.WARN, dbgIndentStr
		418	+ "- evaluateFormula('" + ec.getRefEvaluatorForCurrentSheet().getSheetName()
		419	+ "'/" + new CellReference(ec.getRowIndex(), ec.getColumnIndex()).formatAsString()
		420	+ "): " + Arrays.toString(ptgs).replaceAll("\\Qorg.apache.poi.ss.formula.ptg.\\E", ""));
		421	dbgEvaluationOutputIndent++;
		422	}
		423
390	Stack<ValueEval> stack = new Stack<ValueEval>();	424	Stack<ValueEval> stack = new Stack<ValueEval>();
391	for (int i = 0, iSize = ptgs.length; i < iSize; i++) {	425	for (int i = 0, iSize = ptgs.length; i < iSize; i++) {
392		426
393	// since we don't know how to handle these yet :(	427	// since we don't know how to handle these yet :(
394	Ptg ptg = ptgs[i];	428	Ptg ptg = ptgs[i];
		429	if (dbgEvaluationOutputIndent > 0) {
		430	EVAL_LOG.log(POILogger.INFO, dbgIndentStr + " * ptg " + i + ": " + ptg);
		431	}
395	if (ptg instanceof AttrPtg) {	432	if (ptg instanceof AttrPtg) {
396	AttrPtg attrPtg = (AttrPtg) ptg;	433	AttrPtg attrPtg = (AttrPtg) ptg;
397	if (attrPtg.isSum()) {	434	if (attrPtg.isSum()) {
Lines 497-509 Link Here
497	}	534	}
498	// logDebug("push " + opResult);	535	// logDebug("push " + opResult);
499	stack.push(opResult);	536	stack.push(opResult);
		537	if (dbgEvaluationOutputIndent > 0) {
		538	EVAL_LOG.log(POILogger.INFO, dbgIndentStr + " = " + opResult);
		539	}
500	}	540	}
501		541
502	ValueEval value = stack.pop();	542	ValueEval value = stack.pop();
503	if (!stack.isEmpty()) {	543	if (!stack.isEmpty()) {
504	throw new IllegalStateException("evaluation stack not empty");	544	throw new IllegalStateException("evaluation stack not empty");
505	}	545	}
506	return dereferenceResult(value, ec.getRowIndex(), ec.getColumnIndex());	546	ValueEval result = dereferenceResult(value, ec.getRowIndex(), ec.getColumnIndex());
		547	if (dbgEvaluationOutputIndent > 0) {
		548	EVAL_LOG.log(POILogger.INFO, dbgIndentStr + "finshed eval of "
		549	+ new CellReference(ec.getRowIndex(), ec.getColumnIndex()).formatAsString()
		550	+ ": " + result);
		551	dbgEvaluationOutputIndent--;
		552	if (dbgEvaluationOutputIndent == 1) {
		553	// this evaluation is done, reset indent to stop logging
		554	dbgEvaluationOutputIndent = -1;
		555	}
		556	} // if
		557	return result;
		558
507	}	559	}
508		560
509	/**	561	/**

Lines 33-38 Link Here

(-)src/java/org/apache/poi/util/SystemOutLogger.java (-2 / +6 lines)
33	{	33	{
34	private String _cat;	34	private String _cat;
35		35
		36	@Override
36	public void initialize(final String cat)	37	public void initialize(final String cat)
37	{	38	{
38	this._cat=cat;	39	this._cat=cat;
Lines 45-50 Link Here
45	* @param obj1 The object to log.	46	* @param obj1 The object to log.
46	*/	47	*/
47		48
		49	@Override
48	public void log(final int level, final Object obj1)	50	public void log(final int level, final Object obj1)
49	{	51	{
50	log(level, obj1, null);	52	log(level, obj1, null);
Lines 57-67 Link Here
57	* @param obj1 The object to log. This is converted to a string.	59	* @param obj1 The object to log. This is converted to a string.
58	* @param exception An exception to be logged	60	* @param exception An exception to be logged
59	*/	61	*/
		62	@Override
60	public void log(final int level, final Object obj1,	63	public void log(final int level, final Object obj1,
61	final Throwable exception) {	64	final Throwable exception) {
62	if (check(level)) {	65	if (check(level)) {
63	System.out.println("["+_cat+"] "+obj1);	66	System.out.println("[" + _cat + "]" + LEVEL_STRINGS_SHORT[Math.min(LEVEL_STRINGS_SHORT.length-1, level)] + " " + obj1);
64	if(exception != null) {	67	if (exception != null) {
65	exception.printStackTrace(System.out);	68	exception.printStackTrace(System.out);
66	}	69	}
67	}	70	}
Lines 77-82 Link Here
77	* @see #ERROR	80	* @see #ERROR
78	* @see #FATAL	81	* @see #FATAL
79	*/	82	*/
		83	@Override
80	public boolean check(final int level)	84	public boolean check(final int level)
81	{	85	{
82	int currentLevel;	86	int currentLevel;

Lines 17-23 Link Here

(-)src/java/org/apache/poi/util/POILogger.java (-6 / +13 lines)
17		17
18	package org.apache.poi.util;	18	package org.apache.poi.util;
19		19
20	import java.util.*;	20	import java.util.ArrayList;
		21	import java.util.List;
21		22
22	/**	23	/**
23	* A logger interface that strives to make it as easy as possible for	24	* A logger interface that strives to make it as easy as possible for
Lines 31-42 Link Here
31	*/	32	*/
32	public abstract class POILogger {	33	public abstract class POILogger {
33		34
34	public static int DEBUG = 1;	35	public static final int DEBUG = 1;
35	public static int INFO = 3;	36	public static final int INFO = 3;
36	public static int WARN = 5;	37	public static final int WARN = 5;
37	public static int ERROR = 7;	38	public static final int ERROR = 7;
38	public static int FATAL = 9;	39	public static final int FATAL = 9;
39		40
		41	/** Short strings for numeric log level. Use level as array index. */
		42	protected static final String LEVEL_STRINGS_SHORT[] = {"?", "D", "?", "I", "?", "W", "?", "E", "?", "F", "?"};
		43	/** Long strings for numeric log level. Use level as array index. */
		44	protected static final String LEVEL_STRINGS[] = {"?0?", "DEBUG", "?2?", "INFO", "?4?", "WARN", "?6?", "ERROR", "?8?", "FATAL", "?10+?"};
		45
		46
40	/**	47	/**
41	* package scope so it cannot be instantiated outside of the util	48	* package scope so it cannot be instantiated outside of the util
42	* package. You need a POILogger? Go to the POILogFactory for one	49	* package. You need a POILogger? Go to the POILogFactory for one

Lines 42-48 Link Here

(-)src/documentation/content/xdocs/spreadsheet/eval.xml (-2 / +31 lines)
42	<section><title>Status</title>	42	<section><title>Status</title>
43	<p> The code currently provides implementations for all the arithmatic operators.	43	<p> The code currently provides implementations for all the arithmatic operators.
44	It also provides implementations for approx. 140 built in	44	It also provides implementations for approx. 140 built in
45	functions in Excel. The framework however makes is easy to add	45	functions in Excel. The framework however makes it easy to add
46	implementation of new functions. See the <link href="eval-devguide.html"> Formula	46	implementation of new functions. See the <link href="eval-devguide.html"> Formula
47	evaluation development guide</link> and <link href="../apidocs/org/apache/poi/hssf/record/formula/functions/package-summary.html">javadocs</link>	47	evaluation development guide</link> and <link href="../apidocs/org/apache/poi/hssf/record/formula/functions/package-summary.html">javadocs</link>
48	for details. </p>	48	for details. </p>
Lines 249-255 Link Here
249	existing workbooks with formulas. This can be done in two ways:	249	existing workbooks with formulas. This can be done in two ways:
250	</p>	250	</p>
251	<p>	251	<p>
252	1. Re-evaluate formuals with POI's FormulaEvaluator:	252	1. Re-evaluate formulas with POI's FormulaEvaluator:
253	</p>	253	</p>
254	<source>	254	<source>
255	Workbook wb = WorkbookFactory.create(new FileInputStream("workbook.xls"));	255	Workbook wb = WorkbookFactory.create(new FileInputStream("workbook.xls"));
Lines 308-312 Link Here
308	</li>	308	</li>
309	</ul>	309	</ul>
310	</section>	310	</section>
		311	<section><title>Formula Evaluation Debugging</title>
		312	<p>POI is not perfect and you may stumble across formula evaluation problems (Java exceptions
		313	or just different results) in your special use case. To support an easy detailed analysis, a special
		314	logging of the full evaluation is provided.</p>
		315	<p>The output of this logging may be very large (depends on your EXCEL), so this logging has to be explicitly enabled
		316	for each single formula evaluation. The implementation is not thread safe (uses a single static variable
		317	as logging indicator for easy use), but should not be used in production anyway - only for specific development use.</p>
		318	<p>Example use:</p>
		319	<source>
		320	// activate logging to console
		321	System.setProperty("org.apache.poi.util.POILogger", "org.apache.poi.util.SystemOutLogger");
		322	System.setProperty("poi.log.level", POILogger.INFO + "");
		323
		324	// open your file
		325	Workbook wb = new HSSFWorkbook(new FileInputStream("foobar.xls"));
		326	FormulaEvaluator evaluator = wb.getCreationHelper().createFormulaEvaluator();
		327
		328	// get your cell
		329	Cell cell = wb.getSheet(0).getRow(0).getCell(0); // just a dummy example
		330
		331	// perform debug output for the next evaluate-call only
		332	WorkbookEvaluator.dbgEvaluationOutputForNextEval = true;
		333	evaluator.evaluateFormulaCell(cell);
		334	evaluator.evaluateFormulaCell(cell); // no logging performed for this next evaluate-call
		335	</source>
		336	<p>The special Logger called "POI.FormulaEval" is used (useful if you use the CommonsLogger and a detailed logging configuration).
		337	The used log levels are WARN and INFO (for detailed parameter info and results) - the level are so high to allow this
		338	special logging without beeing disturbed by the bunch of DEBUG log entries from other classes.</p>
		339	</section>
311	</body>	340	</body>
312	</document>	341	</document>

Lines 144-152 Link Here

(-)src/java/org/apache/poi/hssf/usermodel/HSSFSheet.java (-4 / +12 lines)
144	Iterator<CellValueRecordInterface> iter = sheet.getCellValueIterator();	144	Iterator<CellValueRecordInterface> iter = sheet.getCellValueIterator();
145	long timestart = System.currentTimeMillis();	145	long timestart = System.currentTimeMillis();
146		146
147	if (log.check( POILogger.DEBUG ))	147	if (log.check( POILogger.DEBUG )) {
148	log.log(DEBUG, "Time at start of cell creating in HSSF sheet = ",	148	log.log(DEBUG, "Time at start of cell creating in HSSF sheet = ",
149	Long.valueOf(timestart));	149	Long.valueOf(timestart));
		150	}
150	HSSFRow lastrow = null;	151	HSSFRow lastrow = null;
151		152
152	// Add every cell to its row	153	// Add every cell to its row
Lines 172-189 Link Here
172	hrow = createRowFromRecord(rowRec);	173	hrow = createRowFromRecord(rowRec);
173	}	174	}
174	}	175	}
175	if (log.check( POILogger.DEBUG ))	176	if (log.check( POILogger.DEBUG )) {
		177	if (cval instanceof Record) {
176	log.log( DEBUG, "record id = " + Integer.toHexString( ( (Record) cval ).getSid() ) );	178	log.log( DEBUG, "record id = " + Integer.toHexString( ( (Record) cval ).getSid() ) );
		179	} else {
		180	log.log( DEBUG, "record = " + cval );
		181	}
		182	}
177	hrow.createCellFromRecord( cval );	183	hrow.createCellFromRecord( cval );
178	if (log.check( POILogger.DEBUG ))	184	if (log.check( POILogger.DEBUG )) {
179	log.log( DEBUG, "record took ",	185	log.log( DEBUG, "record took ",
180	Long.valueOf( System.currentTimeMillis() - cellstart ) );	186	Long.valueOf( System.currentTimeMillis() - cellstart ) );
		187	}
181		188
182	}	189	}
183	if (log.check( POILogger.DEBUG ))	190	if (log.check( POILogger.DEBUG )) {
184	log.log(DEBUG, "total sheet cell creation took ",	191	log.log(DEBUG, "total sheet cell creation took ",
185	Long.valueOf(System.currentTimeMillis() - timestart));	192	Long.valueOf(System.currentTimeMillis() - timestart));
186	}	193	}
		194	}
187		195
188	/**	196	/**
189	* Create a new row within the sheet and return the high level representation	197	* Create a new row within the sheet and return the high level representation