Granny's Programming Pearls
"inside of every large program is a small program struggling to get out"
JavaRanch.com/granny.jsp
The moose likes Spring and the fly likes Unable to enable logging using CustomizableTraceInterceptor in Spring 3.0.6 Big Moose Saloon
  Search | Java FAQ | Recent Topics | Flagged Topics | Hot Topics | Zero Replies
Register / Login


Win a copy of EJB 3 in Action this week in the EJB and other Java EE Technologies forum!
JavaRanch » Java Forums » Frameworks » Spring
Bookmark "Unable to enable logging using CustomizableTraceInterceptor in Spring 3.0.6" Watch "Unable to enable logging using CustomizableTraceInterceptor in Spring 3.0.6" New topic
Author

Unable to enable logging using CustomizableTraceInterceptor in Spring 3.0.6

Daud Miyan
Greenhorn

Joined: Jul 07, 2010
Posts: 23
I have a very simple setup

I have an applicationContext.xml file like this :


The controller class is also very simple :



My web.xml is :



WowService is also very simple



I have the spring jars of version 3.0.6, aopalliance-1.0.jar, asm-3.1, cglib -2.2 and commons-logging-1.1.1.jar in my lib folder and nothing else. But there is no trace being recorded.. i.e there is no logging being done when we enter the method of WowService, or when we leave it. I can't figure out why.
Mark Spritzler
ranger
Sheriff

Joined: Feb 05, 2001
Posts: 17249
    
    6

Two things.

In your web.xml you have the context-param for the ContextLoaderListener which is pointing to the /WEB-INF/applicationContext.xml file, which is the default location and name, which means you can remove the context-param entry and it works identical.

Also in your DispatcherServlet for the config file location you have it blank. Which I am guessing is because you put both your middle tier and web tier beans in the applicationContext.xml so in just one ApplicationContext, with two concerns mixed. While it works, it isn't a best practice.

Also for the logging, wouldnt you need a config/properties file for the configuration of logging? Meaning the interceptor could still be logging but the logging configuration isn't set up to put it anywhere you are looking? Not sure, just a guess here.

Mark


Perfect World Programming, LLC - Two Laptop Bag - Tube Organizer
How to Ask Questions the Smart Way FAQ
Daud Miyan
Greenhorn

Joined: Jul 07, 2010
Posts: 23
Thanks for that.. but I do have a logging.properties file in the classes folder, which is working fine, with the following content :

org.apache.catalina.core.ContainerBase.[Catalina].level = INFO
org.apache.catalina.core.ContainerBase.[Catalina].handlers = java.util.logging.ConsoleHandler

Its logging a lot of userful information, but not the one which the CustomizableTraceInterceptor is supposed to log. Sorry for not mentioning this earlier.
Mark Spritzler
ranger
Sheriff

Joined: Feb 05, 2001
Posts: 17249
    
    6

Have you tried using


to set it up where your pointcut would be for your service class, not what I just posted as an example that I copied and pasted from docs.

Instead of org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator bean you have.

Mark

Daud Miyan
Greenhorn

Joined: Jul 07, 2010
Posts: 23
Thanks. I tried that, and added the following :


WowService is in the package org.daud. Unfortunately, it still doesn't work. I had to add the aspectJWeaver jar. Finally, I have the following jars in my lob folder :

  • aopalliance-1.0.jar
    asm-3.1.jar
    aspectjweaver-1.6.8.jar
    cglib-2.2.jar
    commons-logging-1.1.1.jar
    org.springframework.aop-3.0.6.RELEASE.jar
    org.springframework.asm-3.0.6.RELEASE.jar
    org.springframework.aspects-3.0.6.RELEASE.jar
    org.springframework.beans-3.0.6.RELEASE.jar
    org.springframework.context.support-3.0.6.RELEASE.jar
    org.springframework.context-3.0.6.RELEASE.jar
    org.springframework.core-3.0.6.RELEASE.jar
    org.springframework.expression-3.0.6.RELEASE.jar
    org.springframework.instrument.tomcat-3.0.6.RELEASE.jar
    org.springframework.instrument-3.0.6.RELEASE.jar
    org.springframework.jdbc-3.0.6.RELEASE.jar
    org.springframework.jms-3.0.6.RELEASE.jar
    org.springframework.orm-3.0.6.RELEASE.jar
    org.springframework.oxm-3.0.6.RELEASE.jar
    org.springframework.test-3.0.6.RELEASE.jar
    org.springframework.transaction-3.0.6.RELEASE.jar
    org.springframework.web.portlet-3.0.6.RELEASE.jar
    org.springframework.web.servlet-3.0.6.RELEASE.jar
    org.springframework.web.struts-3.0.6.RELEASE.jar
    org.springframework.web-3.0.6.RELEASE.jar

  • Daud Miyan
    Greenhorn

    Joined: Jul 07, 2010
    Posts: 23
    Kindly review my logger settings. I am not logging any trace information (simply because Commons Logging doesn't have TRACE level). Should I create log4j.properties also ?
    Mark Spritzler
    ranger
    Sheriff

    Joined: Feb 05, 2001
    Posts: 17249
        
        6

    Not quite sure. But if you run your code through the debugger and set a break point before you call the service, you can check the variables pane to see if you have a reference to the real object or a proxy. Just to make sure you are getting proxied. Let us know.

    Mark
    Daud Miyan
    Greenhorn

    Joined: Jul 07, 2010
    Posts: 23
    Yes.... the wowService variable is getting proxied (CGLIB Bound = true)
    Mark Spritzler
    ranger
    Sheriff

    Joined: Feb 05, 2001
    Posts: 17249
        
        6

    Daud Miyan wrote:Yes.... the wowService variable is getting proxied (CGLIB Bound = true)


    Ok, now the next step. Step through the call to the service. If you can, can you download the SpringFramework sources. Then you can go into the CustomizableTraceInterceptor and put a break point in there to see if it is getting called. If you are using IntelliJ IDEA, it is really really easy. Just hit CTRL-N or Command-N on Mac, type in the class name Custom…. hit enter. Then at the top of the class file it will have a link to download the sources.

    I don't know how to do it in Eclipse, if they even have such a feature. But you can download the source from www.github.com/springsource

    Interesting that it uses CGLib to create a proxy, rather than the normal DynamicProxy class. Unless of course, your Service class is not implementing and interface and you aren't coding to interfaces which is a really really best practice for Java development.

    Mark
    Daud Miyan
    Greenhorn

    Joined: Jul 07, 2010
    Posts: 23
    Step through the call to the service. If you can, can you download the SpringFramework sources. Then you can go into the CustomizableTraceInterceptor and put a break point in there to see if it is getting called.

    Did that, and saw that control was not coming inside the invokeUnderTrace() method. I checked the superclass, and found that in the invoke() method, the isInterceptorEnabled() was returning false. This method was checking whether the trace is enabled in the debugger.

    I then figured that in logging.properties, I had configured only the apache packages to the the FINEST debug level (as posted above), and it wasn't considering spring classes for logging at that level. Therefore, I added the following at the end of logging.properties :



    After that, control began to enter in the invokeUnderTrace() method, and the logging statements got executed without a problem, but unfortunately, there was still no logging to be seen.

    I am seeing the log of catalina.out. Since Spring uses Commons Logging, and i haven't configured Log4J or any other external logging framework, it uses java.util.Logging (the jdk14logger is the type of instances of the logger objects that are being formed, as show in the debugger), and as such logging.properties is being used. Should I look somewhere other than catalina.out ?
    Mark Spritzler
    ranger
    Sheriff

    Joined: Feb 05, 2001
    Posts: 17249
        
        6

    Wouldn't your log file be something like

    localhost.2012-02-08.log and not calalina.out. That is usually where I look.

    Mark
    Daud Miyan
    Greenhorn

    Joined: Jul 07, 2010
    Posts: 23
    localhost.2012-02-08.log - files like these get created when I stop my tomcat instance... whereas catalina.out is updated on the fly... Also, catalina.out has much more information than these files..

    If don't know if its appropriate, but I can upload the war file somewhere and post a link to it here, because war files can't be uploaded here
    Mark Spritzler
    ranger
    Sheriff

    Joined: Feb 05, 2001
    Posts: 17249
        
        6

    Daud Miyan wrote:localhost.2012-02-08.log - files like these get created when I stop my tomcat instance... whereas catalina.out is updated on the fly... Also, catalina.out has much more information than these files..

    If don't know if its appropriate, but I can upload the war file somewhere and post a link to it here, because war files can't be uploaded here


    But different log information goes into different log files. I never found any of my logging in catalina.out, I always had to go into localhost-.log file to see anything. They aren't the same log files.

    Mark
    Daud Miyan
    Greenhorn

    Joined: Jul 07, 2010
    Posts: 23
    According to this question, catalina.out is the file where stdout and stderr goes. Catalina.sh mentions this explicitly. Running this script also points to catalina.out as stated here. I am using Ubuntu 11.04 and am running tomcat 7.0.14 after extracting it from the tar file (i.e. not as a service)
    Daud Miyan
    Greenhorn

    Joined: Jul 07, 2010
    Posts: 23
    I changed the logging.properties file in CATALINA_HOME/conf and replaced java.util.logging.ConsoleHandler.level = FINE with java.util.logging.ConsoleHandler.level = FINEST and now the trace started happening. But that, I suppose, is not the way to do things. When I placed the above line in my application's logging.properties (and reverted changes in tomcat's logging.properties), then no logs were printed for the trace. I can't figure out why
    Mark Spritzler
    ranger
    Sheriff

    Joined: Feb 05, 2001
    Posts: 17249
        
        6

    "catalina.out is the file where stdout and stderr goes. "

    Yeah, but that is not Commons Logging or Log4J. They strictly go to the file listed in their config file. Nothing to do with Tomcat/Catalina.

    That is why it would show up in the localhost log file and never ever in catalina.out. stdout is System.out.println()

    I suggest reading the commons logging documentation or even log4j documentation to understand what goes into log4j.properties or logging.properties.

    Good Luck

    Mark
     
    I agree. Here's the link: http://aspose.com/file-tools
     
    subject: Unable to enable logging using CustomizableTraceInterceptor in Spring 3.0.6
     
    Similar Threads
    Trouble converting a Spring JDBC app to use Spring Hibernate
    Spring MVC - Url Handling Problem
    Liferay Portlet development with Spring: No handler found for request error
    No mapping found for HTTP request with URI - Why won't my page load?
    problem in ResourceBundleViewResolver