12 Replies Latest reply on Apr 29, 2011 2:47 PM by wgpuckett

    Trying to get this logging issue resolved

    wgpuckett

      I have been using jBoss for 6 years now and still have not figured out how to generate consistent separate logs from my servlets.  So far the best I have been able to do is get maybe 75% of my log output to go to a unique log file but also getting 100% of the output to the jboss server log file.   I would like to get this resolved completely.  Unfortunately I usually research and scratch and claw at a solution until my back is up against the wall before I try to ask for help on the forums.  I have Googled this and tried a number of suggestions.  I just can't get anything to work as advertised.    I started out with the attempt of putting the log4j jar file in my EAR file.  This doesn't work because of the way the class loader works in jBoss.  It gets all screwed up when attempting to generate logging from both the EJB and the WEB containers.  I tried ALL of the suggested solutions for that one without any success.

       

      I have come across what seems like the best solution in the jBoss wiki.  After implementing the code as described I don't get any errors, I get a log file created, but nothing ever goes to the log file.  At the moment I am first trying to get the log output from the JPA persistence EntityManagerHelper to go to a specific log file.  Once I get that working I need to implement other logging functionality.

       

      Based on my research it appears the best solution (at least for me) is using a custom repository selector.  So I used the provided class that implements RepositorySelector:

       

       

      {code}

      package mm.logging.repository;

      /**

      * This RepositorySelector is for use with web applications. It assumes that

      * your log4j.xml file is in the WEB-INF directory.

      *

      *

      */

      public class AppRepositorySelector implements RepositorySelector {

          private static boolean initialized = false;

          private static Object guard = LogManager.getRootLogger();

          private static Map repositories = new HashMap();

          private static LoggerRepository defaultRepository;

          public static synchronized void init(ServletConfig servletConfig)

                  throws ServletException {

              init(servletConfig.getServletContext());

          }

          public static synchronized void init(ServletContext servletContext)

                  throws ServletException {

              if (!initialized) // set the global RepositorySelector

              {

                  defaultRepository = LogManager.getLoggerRepository();

                  RepositorySelector theSelector = new AppRepositorySelector();

                  LogManager.setRepositorySelector(theSelector, guard);

                  initialized = true;

              }

              Hierarchy hierarchy = new Hierarchy(new RootLogger(Level.DEBUG));

              loadLog4JConfig(servletContext, hierarchy);

              ClassLoader loader = Thread.currentThread().getContextClassLoader();

              repositories.put(loader, hierarchy);

          }

          public static synchronized void removeFromRepository() {

              repositories.remove(Thread.currentThread().getContextClassLoader());

          }

          // load log4j.xml from WEB-INF

          private static void loadLog4JConfig(ServletContext servletContext,

                  Hierarchy hierarchy) throws ServletException {

              try {

                  String log4jFile = "/WEB-INF/log4j.xml";

                  InputStream log4JConfig = servletContext.getResourceAsStream(log4jFile);

                  Document doc = DocumentBuilderFactory.newInstance().newDocumentBuilder().parse(log4JConfig);

                  DOMConfigurator conf = new DOMConfigurator();

                  conf.doConfigure(doc.getDocumentElement(), hierarchy);

              } catch (Exception e) {

                  throw new ServletException(e);

              }

          }

          private AppRepositorySelector() {

          }

          public LoggerRepository getLoggerRepository() {

              ClassLoader loader = Thread.currentThread().getContextClassLoader();

              LoggerRepository repository = (LoggerRepository) repositories.get(loader);

              if (repository == null) {

                  return defaultRepository;

              } else {

                  return repository;

              }

          }

      }

      {code}

       

       

      Then I put in the context listener

       

      {code}

      package mm.logging.repository;

      import javax.servlet.ServletContextEvent;

      import javax.servlet.ServletContextListener;

      public class AppContextListener implements ServletContextListener {

          public void contextDestroyed(ServletContextEvent contextEvent) { }

       

       

          public void contextInitialized(ServletContextEvent contextEvent) {

              try {

                   AppRepositorySelector.init(contextEvent.getServletContext());

              } catch (Exception ex) {

                   System.err.println(ex);

              }

          }

      }

      {code}

       

      and then added the listener to the web.xml file

       

      {code:xml}
      <listener>
         <listener-class>mm.logging.repository.AppContextListener</listener-class>
      </listener>
      {code:xml}

       

      And then put the following log4j.xml file in the WEB-INF folder:

       

       

      {code:xml}

      <log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">

         <appender name="JPA" class="org.jboss.logging.appender.RollingFileAppender">

           <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>

           <param name="File" value="D:/WWW/CWDC/logs/jpa.log"/>

           <param name="Append" value="false"/>

           <param name="MaxFileSize" value="500KB"/>

           <param name="MaxBackupIndex" value="1"/>

           <layout class="org.apache.log4j.PatternLayout">

              <param name="ConversionPattern" value="%d %-5p [%c] %m%n"/>

           </layout>

        </appender>

        <category name="CWDCPU">

          <priority value="DEBUG" />

          <appender-ref ref="JPA"/>

        </category>

      </log4j:configuration>

      {code:xml}

       

       

      The EntityManagerHelper has the followoing code:

       

      {code}
      logger = Logger.getLogger("CWDCPU");
      logger.setLevel(Level.ALL);
      {code}

       

      And in the JPA code the logging looks something like:

       

      {code}
      EntityManagerHelper.log("saving AccountStructureTbl instance", Level.INFO, null);
      {code}

       

      When jBoss starts don't see any sort of diagnostic indicating this did not start properly.  I can't say I see anything that says it does either.

       

      I end up getting all of the JPA logging on the console and nothing in the log file itself.

       

      I will admit that I am much more familiar with the log4j properties file rather than the xml but I tried to keep it as simple as possible. 

       

      Where did I go wrong?

        • 1. Trying to get this logging issue resolved
          justkeys

          Your question is not entirly clear.

           

          If the problem is

           

          - you have 2 servlets A and B, probably both using the same underlying code (eg JPA)

          - you want the logging from both, but in different files a.log and b.log

           

          then i'ld propose to use MDC (a class with static methods, in log4j, which is inside jboss-logging). This is a way to "stamp" each log-line with a particular tag that sticks to the current thread.

           

          To fill this tag, you need to intercept your thread somehow, eg using a servlet filter. In there, have a try / finally where you set / clear some MDC key-value pair: MDC.put("servletname","a" or "b"). Internally, a ThreadLocal takes care of holding on to this value.

           

          Use a single server.log file (like in default jboss). In your logging pattern, use %X{servletname} this will result in the "a" or the "b" one each line that gets logged. Because it is on each line, it's easy to split up your server.log in 2 files in a post processing step. 

           

          Note: since the mechanism is based on ThreadLocal, the tag will not be printed if you spawn parts of your processing to other threads, unless you do fill the MDC for these threads as well.

          Note: you need to depend on log4j in order to compile your source code (the call the MDC.put method), (or use reflection to reach this method) but you should not package the log4j.jar in your war: log4j is on the runtime jboss classpath.


          avax.servlet

          • 2. Trying to get this logging issue resolved
            wgpuckett

            I'm sorry it is not clearly stated.  My problem is that I can't get log messages from my entire web ap to appear in a log file completely separate from the JBoss log file.  No matter what I do I end up with log messages showing up on the JBoss log file.  I want to create distinct separate log files in separate directories for ALL of my applications.

             

            I picked the ouput of the JPA code simply because it is already there.  It should be no different directing the output of the JPA to a distinct log file than any other application.  The significance of the JPA code is that it instantiates Logger using a constant value rather than the class name.  But that should not make a difference to Logger.  Instead of all the Logger output going to the console I want it to go to a log file.   I made the changes as listed in my initial post and the result was no difference.  JBoss still ended up overriding my Logger setup and the JPA output continues to go to the JBoss console.

             

            The significance is that if I can figure out how to get the JPA log to it's own log file then I can also get my application code to generate log entries into it's own distinct log file.  I'm not talking about a specific servlet.  I mean I want to be able to direct all "com.myapp" to a separate log file.  It sounds easy.  But it has proven NOT to be.  No matter what I try to do JBoss ends up overriding any setup I attempt and my application log entries go to the JBoss log file.  I have a server that will be running several separate virtual web applications.  I need to have separate distinct log files for each application.  Right now I get everything in ONE log file.

             

            I have tried 3 or 4 distinct solutions to make this happen with only limited success.  I have only been able to get part of the application to consistently route log messages to a separate log file.  When I deploy the second application my log files will be a disaster if I can't figure this out.

            • 3. Trying to get this logging issue resolved
              wgpuckett

              Is this not being answered because of lack of interest or lack of knowledge?  Am I asking a question everyone that knows the answer considers a stupid question?  I can't help but be curious. 

              • 4. Trying to get this logging issue resolved
                jaikiran

                I did not answer this because, to be honest, I'm really tired of seeing all these logging issues and all these numerous ways of trying to get it to work.

                 

                Anyway, let's start this from the beginning. Which version of JBoss AS are you using? What kind of a application are you deploying - .war or .ear? Let's for a moment keep aside the repository selector approach and see what really needs to be done to get this working. So you have a application which has classes belonging to com.myapp package and you use log4j in those classes. You want those log message to be logged in a specific blah.log file instead of the default server.log file. Is that correct? Also, one of your post talks about "when you deploy another application" things go wrong. So you have 2 applications both having com.myapp classes and both logging using log4j and you want each of those applications to log to a separate file?

                 

                Are you willing to do changes to the log4j.xml/jboss-log4j.xml that is shipped in JBoss AS? Or do you want to ship your own version of the config file?

                • 5. Trying to get this logging issue resolved
                  peterj

                  Two reasons I can think of. First, yoiu never said which version of JBoss AS., Logging in 6.0.0 is way different than in 5.1.0 and earlier. Second, you are trying to do something fairly complicated with multiple separate logs with unique log entries, and as Jaikiran pointed out, that can get rather complex depending on exactly what you want to see.

                  • 6. Trying to get this logging issue resolved
                    wgpuckett

                    Yes, there are a lot of questions on the forums regarding loggin with JBoss.  That should be an indicator that there is a serious problem with that topic and needs some attention.  It should not be this difficult to make it happen.  Maybe it has been fixed in more recent versions.  However, if you think it is tiresome seeing all the questions about logging think of how tiresome it is to attempt all the various suggestions for fixes just to find that none of them work.

                     

                    I am using version 4.2.3.  Yes, I would LOVE to upgrade.  But I am a single developer maintaning an application and supporting the JBoss installation.  I tried installing JBoss 5.x and implementing my application in it and it didn't work.  I don't have the time at this point to stop my development efforts to figure out a new installation/configuration.  v4.2.3 works great for us.  When I can spare a week or two to investigate how to configure the latest and greatest of JBoss I will do so.

                     

                    IMHO when you are running several virtual applications on the same instance of JBoss the logging should be separated by default.  Who would want multiple applications generating a single combined log?  Also, JBoss itself generates quite a bit of logging output.  It just becomes more difficult to have to search through the JBoss log entries just to find specific entries from the application itself.

                     

                    Actually at this point I have two applications running on one instance of JBoss.  One is an enterprise application (EAR) and the other is a Web Application (WAR).  The applications are for two totally separate clients.

                     

                    I have abandoned the repository selector.  I couldn't begin to get it to work without some feedback.  I didn't get any so I discarded that effort.

                     

                    In my further investigations I came across a message board post suggesting you make sure there are no extra log4j jar files in the WAR file.  It turned out that the Eclipse deployment was putting a log4j jar file in the WAR files since it was part of the J2EE library.  I can't see there is a way to configure Eclipse to NOT include that jar so I have started taking it out each time I deploy.  This has eliminated a warning I was getting at JBoss startup that I didn't realize was a problem.  Essentially it was resulting in a class cast exception but was covering that up with a more vague error message.  I started getting some messages out when I did this.

                     

                    I have added my configuration entries to the jboss-log4j.xml file.  It appears at this point that I am getting log entries from the Web application on both the separate application log AND the JBoss log.  On the Enterprise application I am predominantly getting output from the Web container on the application log.  But the output from the EJB Container is going to the JBoss log.  This is wierd since the package names on both the Web and EJB containers have the same prefix.  If one works one way the other should also work the same.  But it doesn't.

                     

                    By far my preference would be to leave the jboss-log4j.xml file alone and ship the application with it's own log4j configuration.  I would rather leave modifications to JBoss itself to the bare minimum and leave application specific stuff in the application.  I tried adding a log4j.xml file in the lib directory of WEB-INF and got absolutely nothing out.

                     

                    I really appreciate the response.

                    • 7. Trying to get this logging issue resolved
                      genman
                      I have added my configuration entries to the jboss-log4j.xml file.  It appears at this point that I am getting log entries from the Web application on both the separate application log AND the JBoss log.  On the Enterprise application I am predominantly getting output from the Web container on the application log.  But the output from the EJB Container is going to the JBoss log.  This is wierd since the package names on both the Web and EJB containers have the same prefix.  If one works one way the other should also work the same.  But it doesn't.

                       

                      If you use your app-specific log4j.jar file, then there's basically two copies of each log4j class. As you have seen, the classes part of the container get the container log4j.jar and the jboss-log4j.xml configuration. Your stuff loads classes from your own log4j.jar and works, but not so for the container. Anyway, it's a mess!

                       

                      If I were you:

                       

                      Forget putting log4j.jar in your deployment.

                       

                      For every entry point in your code, specifically servlet requests or new threads you create, use the log4j MDC class and mark that thread as belonging to your application. You can use something like this, for example: http://www.rtner.de/software/MDCUserServletFilter.html

                       

                      Basically you do: MDC.put("app", "name of your app")

                       

                      Then write a filter that filters these events:

                      http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/spi/Filter.html

                      See this for inspiration:

                      http://stackoverflow.com/questions/142845/splitting-log4j-output-with-quartz-worker-threads

                       

                      Create a global jboss-log4j.xml file that contains appenders that filter out only the messages with the MDC set.

                       

                       

                      ... There's a lot of forum threads about the same stuff, logging in particular, because people have very particular needs.

                      • 8. Trying to get this logging issue resolved
                        peterj
                        It appears at this point that I am getting log entries from the Web application on both the separate application log AND the JBoss log.

                        That is because all loggers inherit from the root logger and the root logger says to log to FILE and CONSOLE. Once way to get your app logging not to go to FILE (server.log) is to remove FILE from the root logger.

                         

                        Of course, that will result in nothing going to FILE because I don't think that any of the loggger categories reference the FILE logger. So you should add a few base categories, such as org.jboss, and reference the FILE appender for them. The best thing to do is scan the current server.log and see what base categories are logged. Note that if you add org.jboss and reference FILE, then categories such as org.jboss.serial and org.jboss.management (which already appear in the jboss-log4j.xml file) inherit from org.jboss and thus will already got to FILE, thus you do not need to add the reference to FILE to those.

                         

                        In general, this is all just about how to properly configure Log4J and has little to do with JBoss AS itself.

                         

                        By far my preference would be to leave the jboss-log4j.xml file alone and ship the application with it's own log4j configuration.

                        I assume you have seen this: http://community.jboss.org/message/198691#198688

                        • 9. Trying to get this logging issue resolved
                          wgpuckett

                          I think I finally have this working.  Honestly I'm not sure what I did to fix it.  I hate it when that happens.  I kept trying various options that I found on message boards and testing until something worked.  I tried then abandoned the configuration as suggested in the post above.  It never wrote anything to the log.  So I concentrated on making it work with everything in the jboss-log4j.xml file.  Analyzing the working version with what I had before I really can't tell any difference.  It may be that I never got all the pieces deployed at the same time before this.  Sometimes Eclipse and JBoss get a bit out of synch from what I have experienced.

                           

                          But I still had everything in the jboss-log4j.xml file.  As I said I tried setting it up as described in the thread listed above and got a blank log.  So I removed the log4j.jar file and lib directory from the EAR and just left the log4j.xml file at the EAR root.  I am now getting a log file generated for my app.  Now I have the log configuration application specific and deployed with the application, which is what I wanted.

                           

                          Logging in JBoss has been a frustrating experience.  I don't remember ever seeing a post suggesting that all you need is the configuration file at the EAR level.  Folks are always telling you to do some funky things with the log4j jar file.  I think that complicates the situation.  Having an extra log4j jar file in the EAR/WAR seems to cause an error message as JBoss starts up but it doesn't appear to cause any logging failure unless it is at the root level of the EAR itself.

                           

                          I really appreciate the responses.  It helped me sort out what I was and was not doing wrong.

                          • 10. Trying to get this logging issue resolved
                            wgpuckett

                            One further item regarding deploying application specific log4j configurations.  For WEB applications that are deployed as separate WAR files.  The log4j.xml file needs to be in the classes directory of the WAR.  However, in Eclipse you normally won't see the classes directory.  You should place the xml file in the src directory.  It will get placed in the classes directory at deployment.  DO NOT put it in the META-INF directory.  It won't work there.

                            • 11. Trying to get this logging issue resolved
                              setianusa

                              Hi Glenn,

                               

                              If you don't mind, maybe you could share with us your solution, which config files, what have you done, how the ear/war structure should be, etc.

                               

                              Thanks,

                              Tom

                              • 12. Trying to get this logging issue resolved
                                wgpuckett

                                First there is nothing that is needed to be done with any log4j libraries.  Most of the posts I found had something to say about managing a log4j.jar file within the application.  That is totally unnecessary.  Also, I discovered that the way I have it configured it doesn't matter if your EAR/WAR file has a log4j.jar file in it.  I can't say for sure which jar file gets used, JBoss or your distrubution, it just works.

                                 

                                In my Eclipse workspace I have my J2EE application set up as 3 projects.  The base project (MyApp), the EJB project (MyApp EJB) and the WEB project (MyApp WEB).  I placed a log4j.xml configuration file in the root level of the base project (MyApp).  This configuration file has the Log4j setup for both the EJB and the WEB projects.  It appears to be working fine and does not interfere with the JBoss log files at all.

                                 

                                The other application it is a Web application only.  I placed the log4j.xml file at the root level of the src directory.  This is very different from most posts which tell you to put it in WEB-INF\lib.  Since the struts.xml file is at the src root I tried the log4j.xml file there and it worked.  The deployment process ends up putting log4j.jar in the WEB-INF\lib directory of the WAR file but that does not appear to be used.  I have tested with it there and with it deleted with no effect on my logs.