[teiid-issues] [JBoss JIRA] Closed: (TEIID-1396) XML_PLAN output to server log too verbose for DEBUG level logging

Thu Mar 24 00:38:47 EDT 2011

     [ https://issues.jboss.org/browse/TEIID-1396?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Steven Hawkins closed TEIID-1396.
---------------------------------


> XML_PLAN output to server log too verbose for DEBUG level logging
> -----------------------------------------------------------------
>
>                 Key: TEIID-1396
>                 URL: https://issues.jboss.org/browse/TEIID-1396
>             Project: Teiid
>          Issue Type: Bug
>          Components: Query Engine
>    Affects Versions: 7.1.1
>         Environment: RHEL 5, SOA-P 5.1 ER5, JBDS 4.0 Beta2 (H33)
>            Reporter: Paul Nittel
>            Assignee: Steven Hawkins
>             Fix For: 7.1.1, 7.3
>
>
> I was executing the E2E Staging Table test script and executed a query of the XML document from Designer. It took a long time--longer than I'd anticipated--so I looked at the server log to see what had happened. Turns out the server log had grown to 1.2GB in roughly 10 minutes. Checking the log (carefully!) I found XML_PLAN entries accounted for 8,759,795 lines of the 10,267,566 line log file. A sample of the entries look like:
> 2010-12-14 10:01:47,612 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) [showState] currentObject: shows
> 2010-12-14 10:01:47,612 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) [showState] currentObject.getNillableDescriptor(): null
> 2010-12-14 10:01:47,612 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) [showState] workingElements: [programId, programName, rating]
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) [showState] currentParent.getParent(): ResultSet
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) Executing instruction NEXT TVDOC.TVGUIDEROOTALL.MAPPINGCLASSES.SHOWS_1
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) NEXT TVDOC.TVGUIDEROOTALL.MAPPINGCLASSES.SHOWS_1
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) Processor Environment popped program w/ recursion count 0 ; 2  programs left.
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) Executing instruction LOOP TVDOC.TVGUIDEROOTALL.MAPPINGCLASSES.SHOWS_1
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) WHILE repeating for result set: TVDOC.TVGUIDEROOTALL.MAPPINGCLASSES.SHOWS_1 , block program: PROGRAM size 7
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) Pushed non-recursive program w/ recursion count 0
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) Executing instruction ELEM shows (namespaces )
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) 
>  [showState] State Vars at: addElement(2) - TOP
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) [showState] currentParent: producer
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) [showState] currentObject: shows
> 2010-12-14 10:01:47,613 DEBUG [org.teiid.PROCESSOR.XML_PLAN] (Worker28_QueryProcessorQueue599) [showState] currentObject.getNillableDescriptor(): null
> Speaking with Ramesh, he suggests possibly moving this type of output to TRACE.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira