PDA

View Full Version : How to trace SQL



ejain
10-04-2003, 12:19 AM
Is there any way to have Mondrian print out the actual SQL statements that are being issued?

avix
10-04-2003, 05:20 AM
Try to set mondrian.trace.level in mondrian.properties or as system property (-Dmondrian.trace.level=1).
Andreas

ejain
10-04-2003, 07:22 AM
Thanks, mondrian.trace.level was precisely what I was looking for.

mondrian_slane
08-01-2006, 05:00 AM
Where does output go? I'm running this in Tomcat 5.5
Thanks

bromgrev
08-04-2006, 05:14 AM
The output of mondrian.trace.level goes to [System.out] which should appear in your Eclipse console window. Here is the log4j.properties file that I use to dump it to a file. Enjoy!
################################################################################
# Mondo
#
# - Log4j 1.2.8
#
# Steven M. Baynes
#
################################################################################
project.name=mondo
space.path=C:/Java/workspace
pattern.d1=%-5r [%t] %-5p %20c %x - %m%n
pattern.s1=%5p [%d{dd MMM yy HH:mm:ss}] %20C (%F:%M:%L) \n\t - %m%n
pattern.s2=-> %d %5p %C (%F:%M:%L) \n\t - %m%n
pattern.s3=%5p [%d{dd MMM yy HH:mm:ss}] %-40C [Thread:%t] - %m%n
pattern.s4=%5p [%d{dd MMM yy HH:mm:ss}] %-40C - %m%n
##################################### direct log messages to [TomcatConsole] ###
log4j.appender.TomcatConsole=org.apache.log4j.ConsoleAppender
log4j.appender.TomcatConsole.Target=System.out
log4j.appender.TomcatConsole.Threshold=DEBUG
log4j.appender.TomcatConsole.layout=org.apache.log4j.PatternLayout
log4j.appender.TomcatConsole.layout.ConversionPattern=${pattern.s3}
######################################## direct log messages to [AppLogFile] ###
# here is our daily logger - SMB
log4j.appender.DailyLogFile=org.apache.log4j.DailyRollingFileAppender
log4j.appender.DailyLogFile.File=${catalina.home}/logs/${project.name}-daily.log
#log4j.appender.DailyLogFile.File=${space.path}/logs/${project.name}-daily.log
log4j.appender.DailyLogFile.DatePattern='.'yyyy-MM-dd'.log'
log4j.appender.DailyLogFile.Threshold=DEBUG
log4j.appender.DailyLogFile.layout=org.apache.log4j.PatternLayout
log4j.appender.DailyLogFile.layout.ConversionPattern=${pattern.s3}
############################################################# set log levels ###
log4j.rootLogger=WARN, TomcatConsole, DailyLogFile
# Here is our Mondrian-specific logging levels
#log4j.logger.mondrian=DEBUG
log4j.logger.mondrian.rolap=DEBUG
################################################################################
#
# End of File
#
################################################################################

mondrian_slane
08-08-2006, 09:14 AM
I don't understand where Eclipse comes in. I'm running this as a webapp via Tomcat 5.5.
Where would I put a log4j.properties file? Would this be automatically picked up by the server and used? I'm completly unfamiliar with log4j and how it works.

sbirney
08-08-2006, 09:52 AM
The SQL traces go to standard out by default. So, eclipse users see it in their consoles.
You can also change the mondrian property mondrian.debug.out.file, to have the SQL traces written to any filename you want.
I believe this SQL trace mechanism works separate from log4j.
But, most of the code does have useful logging statements with log4j, which you can enable by putting your log4j.properties in WEB-INF/classes.

mondrian_slane
08-09-2006, 02:58 AM
I can't seem to get the trace to log anywhere. This is my mondrian.properties file:
# Allow the use of aggregates
mondrian.rolap.aggregates.Use=true
mondrian.rolap.aggregates.Read=true
mondrian.native.topcount.enable=true
mondrian.native.filter.enable=true
# mondrian.properties
mondrian.result.limit=0
mondrian.trace.level=1
mondrian.debug.out.file=mondrian_log.log
I've also tried giving a partial path (/WEB-INF/mondrian_log.log) as well as a full path (C:/Program Files/Apache Software Foundation/Tomcat 5.5/webapps/mondrian/WEB-INF/mondrian_log.log). I tried it without the line completely.
I tried starting Tomcat via system services and by running the .exe itself.
I've tried with the mondrian.properties file in /WEB-INF/, in /WEB-INF/classes/, in /Tomcat 5.5/bin/.
None of these have given me the output of what mondrian is passing on to my database. From the database, I can see the connection through tomcat, and I can see reads are being performed (I can't see of what tables, though). However, it returns back to JPivot with "JPivot had an error..." that I've read in other topics that may mean there is a mistake in a query somewhere. I really need to see this trace to try to find the problem.
It seems like something simple, but I am apparantly missing it. I hope someone can clarify.
Thanks,
Sam

sbirney
08-09-2006, 05:17 AM
i don't quite have enough info to figure out what happened. it is possible that you enabled SQL tracing, but the error occurred before any SQL was generated by mondrian. what does the full error in the tomcat log say?

mondrian_slane
08-09-2006, 07:17 AM
From Tomcat's stdout_DATE.log:
[JPivot] 09 Aug 2006 08:05:42,786 ERROR [Session C5F0ABE28DEA3ED9B38E938B2A7AF266] com.tonbeller.wcf.controller.RequestFilter$MyHandler#handleException: exeption
org.apache.jasper.JasperException: javax.servlet.jsp.JspException: An error occurred while evaluating custom action attribute "test" with value "${query01.result.overflowOccured}": An error occurred while getting property "result" from an instance of class com.tonbeller.jpivot.tags.OlapModelProxy (com.tonbeller.jpivot.olap.model.OlapException: mondrian.olap.MondrianException: Mondrian Error:Internal error: Error while executing query [select {[Customer].[Root Id].Members} ON COLUMNS,
{[Date Entered].[Year].Members} ON ROWS
from [Invoices]
])
at org.apache.jasper.servlet.JspServletWrapper.handleJspException(JspServletWrapper.java:510)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:375)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:314)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:264)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at com.tonbeller.wcf.controller.RequestFilter$MyHandler.normalRequest(RequestFilter.java:139)
at com.tonbeller.wcf.controller.RequestSynchronizer.handleRequest(RequestSynchronizer.java:127)
at com.tonbeller.wcf.controller.RequestFilter.doFilter(RequestFilter.java:263)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Unknown Source)
[JPivot] 09 Aug 2006 08:05:42,802 ERROR [Session C5F0ABE28DEA3ED9B38E938B2A7AF266] com.tonbeller.wcf.controller.RequestFilter$MyHandler#handleException: cause
javax.servlet.ServletException: javax.servlet.jsp.JspException: An error occurred while evaluating custom action attribute "test" with value "${query01.result.overflowOccured}": An error occurred while getting property "result" from an instance of class com.tonbeller.jpivot.tags.OlapModelProxy (com.tonbeller.jpivot.olap.model.OlapException: mondrian.olap.MondrianException: Mondrian Error:Internal error: Error while executing query [select {[Customer].[Root Id].Members} ON COLUMNS,
{[Date Entered].[Year].Members} ON ROWS
from [Invoices]
])
at org.apache.jasper.runtime.PageContextImpl.doHandlePageException(PageContextImpl.java:858)
at org.apache.jasper.runtime.PageContextImpl.handlePageException(PageContextImpl.java:791)
at org.apache.jsp.testpage_jsp._jspService(testpage_jsp.java:258)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:97)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:332)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:314)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:264)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at com.tonbeller.wcf.controller.RequestFilter$MyHandler.normalRequest(RequestFilter.java:139)
at com.tonbeller.wcf.controller.RequestSynchronizer.handleRequest(RequestSynchronizer.java:127)
at com.tonbeller.wcf.controller.RequestFilter.doFilter(RequestFilter.java:263)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Unknown Source)

mondrian_slane
08-16-2006, 08:13 AM
Has this log message been any help? Is there anything else I can provide to help someone determine why I'm not getting SQL logged?

sbirney
08-16-2006, 09:31 AM
sorry I did not see the error stack trace you posted earlier... it's a little hard for me to make sense of this, but it looks like some overflow occurred while performing the query. looking at the code for executing the query in RolapUtil.java, it looks like it should still produce SQL trace debugOut statements when enabled, even if there is an exception, so it is still a mystery why you are not seeing those.
it additionally logs the info through log4j. try enabling debug for this class, by putting this in your log4j.properties:
log4j.logger.mondrian.rolap.RolapUtil=debug
and you should get some useful debugging output about the sql being executed.
you can also try limiting your mdx query to avoid the overflow -- maybe by aggregating to a higher level instead of showing all customer_ids.

sbirney
08-16-2006, 09:43 AM
one good theory that would explain what you are seeing is if the overflow error is occurring while generating sql from the mdx. if that is the case, there might not be any sql to log. so, i would first try with query that returns less output if you have a lot of customer_ids in your data for this query.

mondrian_slane
08-17-2006, 06:18 AM
Thanks for responding to my issues. A couple things have come up.
First off, I tried what I thought was a limit on the customer axis by specifying a specific root id:
... ([Customer].[Root Id].[75]) on columns ...
I ran this, got a Java Heap error and went to check the log. I was able to find an SQL call against my database in the stdout error log (Yeah!). However, it complained about trying to parse the mdx query and the sql query it sent did not limit it by the root id as I expected. Since the error that was reported was Java Heap, I checked the runtime memory allowed by Tomcat. It had been reset and was at default max memory. I changed this to 512 because using the Tomcat manager I've seen it attempt to get 400+MB to run in the past. Now, after changing the memory limit I tried the query again and got a connection timeout, if I try to reload it says "JPivot is busy..." The stdout log is empty. I've let this sit for a couple of hours in the past and never gotten a response.
So my new questions are:
1) How do I limit my mdx query?
2) Does limiting the mdx query limit the sql query?
3) Why doesn't anything return when I give it more memory? What's happening?
Sorry for the long post.
Thanks again for the help.
Sam