logging to a local JMS problem

[mkania]

hi All,

I encountered this problem several times while reading the forum.
I learned that if I wanted to log to a local jms, due to dependency problem,
I had to make a JMS appender run after the naming service and the connection
factory had started. And I also learned that it was better to make the appender
delegate to an MBean with dependencies upon services mentioned above.
That is what I did. However while starting a JBoss instance, at the
moment of getting the MBean started, it seems to hang. It doesn't run any more.

My configuration files are as follows:

jboss-service.xml:
___________________

 <!-- ================================= -->
 <!-- Log4j Initialization -->
 <!-- ================================= -->

 <mbean code="org.jboss.logging.Log4jService" name="jboss.system:type=Log4jService,service=Logging">
 <attribute name="ConfigurationURL">resource:log4j.xml</attribute>
 <attribute name="Log4jQuietMode">true</attribute>
 </mbean>

 <!-- my service goes here -->
 <mbean code="pl.com.supermedia.booker.logdelegate.JMSAppenderDelegate" name="booker.logdelegate:service=JMSAppenderDelegate">
 <attribute name="ConfigFileName">JMSAppenderConfig.xml</attribute>
 <depends>jboss:service=Naming</depends>
 <depends>jboss.jca:service=ConnectionFactoryDeployer</depends>
 </mbean>

 <!-- ================================= -->

MBean interface and implementation:
_______________________________

/**
 * MBean implementation class.
 * It reads a log4j JMSAppender configuration from a file.
 */
public class JMSAppenderDelegate extends ServiceMBeanSupport
 implements JMSAppenderDelegateMBean
{
 private String configFileName;

 public void startService() throws Exception {
 loadLog4JConfig();
 log.info("JMSAppenderDelegate service started");
 }

 public void stopService() {
 log.info("JMSAppenderDelegate service stopped");
 }

 public String getConfigFileName() {
 return configFileName;
 }

 public void setConfigFileName(String configFileName) {
 this.configFileName = configFileName;
 }

 /**
 * load log4j.xml
 *
 * For now it is read from a file, which path is a constant here.
 * TODO: Should read it from a service attribute
 */
 private void loadLog4JConfig() {
 try {
 log.info(CONFIG_XML);
 URL config = getClass().getResource(CONFIG_XML);
 log.info("Configuring from: " + config.toExternalForm());

 DOMConfigurator.configure(config);
 } catch (Exception e) {
 log.error("Failed to load log4j config", e);
 }
 }

 private static String CONFIG_XML = "/config/JMSAppenderConfig.xml";

}


/**
 * Interface for the MBean.
 */
public interface JMSAppenderDelegateMBean extends ServiceMBean {
 public String getConfigFileName();
 public void setConfigFileName(String configFileName);
}

JMSAppenderConfig.xml - log4j JMSAppender configuration file:
____________________________________________________

it is located here:

logdelegate.jar

 |
 +--- /config
 | |
 | + JMSAppenderConfig.xml
 |
 +--- /Meta-inf
 | |
 | + Manifest.mf
 |
 +---/pl/com/supermedia/booker/logdelegate
 |
 + JMSAppenderDelegate.class
 + JMSAppenderDelegateMBean.class

and its body:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j='http://jakarta.apache.org/log4j/'>

 <appender name="AllEventsJMSAppender" class="org.apache.log4j.net.JMSAppender">
 <param name="InitialContextFactoryName" value="org.jnp.interfaces.NamingContextFactory"/>
 <param name="ProviderURL" value="jnp://localhost:1099"/>
 <param name="URLPkgPrefixes" value="org.jboss.naming:org.jnp.interfaces"/>
 <param name="TopicConnectionFactoryBindingName" value="ConnectionFactory"/>
 <param name="TopicBindingName" value="topic/eventLogging"/>
 <param name="UserName" value="logger"/>
 <param name="Password" value="logger"/>
 <param name="LocationInfo" value="true"/>
 </appender>

 <!-- add this appender to the root category -->
 <root>
 <appender-ref ref="AllEventsJMSAppender"/>
 </root>

</log4j:configuration>

Appropriate JBoss console output:
_____________________________

15:50:09,365 INFO [Server] Starting JBoss (MX MicroKernel)...
15:50:09,385 INFO [Server] Release ID: JBoss [WonderLand] 3.2.3 (build: CVSTag=JBoss_3_2_3 date=200311301445)
15:50:09,385 INFO [Server] Home Dir: C:\jboss-3.2.3
15:50:09,385 INFO [Server] Home URL: file:/C:/jboss-3.2.3/
15:50:09,395 INFO [Server] Library URL: file:/C:/jboss-3.2.3/lib/
15:50:09,395 INFO [Server] Patch URL: null
15:50:09,395 INFO [Server] Server Name: booker
15:50:09,395 INFO [Server] Server Home Dir: C:\jboss-3.2.3\server\booker
15:50:09,405 INFO [Server] Server Home URL: file:/C:/jboss-3.2.3/server/booker/
15:50:09,405 INFO [Server] Server Data Dir: C:\jboss-3.2.3\server\booker\data
15:50:09,405 INFO [Server] Server Temp Dir: C:\jboss-3.2.3\server\booker\tmp
15:50:09,405 INFO [Server] Server Config URL: file:/C:/jboss-3.2.3/server/booker/conf/
15:50:09,405 INFO [Server] Server Library URL: file:/C:/jboss-3.2.3/server/booker/lib/
15:50:09,405 INFO [Server] Root Deployment Filename: jboss-service.xml
15:50:09,426 INFO [Server] Starting General Purpose Architecture (GPA)...
15:50:10,096 INFO [ServerInfo] Java version: 1.4.2_05,Sun Microsystems Inc.
15:50:10,096 INFO [ServerInfo] Java VM: Java HotSpot(TM) Client VM 1.4.2_05-b04,Sun Microsystems Inc.
15:50:10,096 INFO [ServerInfo] OS-System: Windows 2000 5.0,x86
15:50:10,197 INFO [ServiceController] Controller MBean online
15:50:10,527 INFO [MainDeployer] Started jboss.system:service=MainDeployer
15:50:10,707 INFO [MainDeployer] Adding deployer: org.jboss.deployment.JARDeployer@10f6d3
15:50:10,707 INFO [JARDeployer] Started jboss.system:service=JARDeployer
15:50:10,767 INFO [MainDeployer] Adding deployer: org.jboss.deployment.SARDeployer@1c9a690
15:50:10,777 INFO [SARDeployer] Started jboss.system:service=ServiceDeployer
15:50:10,777 INFO [Server] Core system initialized
15:50:10,807 INFO [MainDeployer] Starting deployment of package: file:/C:/jboss-3.2.3/server/booker/conf/jboss-service.xml
15:50:16,235 INFO [Log4jService$URLWatchTimerTask] Configuring from URL: resource:log4j.xml
15:50:16,726 INFO [LocalJBossServerDomain] Started jboss.management.local:j2eeType=J2EEDomain,name=Manager
15:50:16,726 INFO [Log4jService] Started jboss.system:type=Log4jService,service=Logging
15:50:16,736 INFO [AbstractDeploymentScanner$ScannerThread] Running
15:50:16,756 INFO [WebService] Started WebServer with address: 0.0.0.0:8083
15:50:16,776 INFO [WebService] Using RMI server codebase: http://test:8083/
15:50:16,786 INFO [WebService] Started jboss:service=WebService
15:50:16,786 INFO [NamingService] Starting jnp server
15:50:16,986 INFO [NamingService] Started jnpPort=1099, rmiPort=1098, backlog=50, bindAddress=/0.0.0.0, Client SocketFactory=null, Ser
ver SocketFactory=org.jboss.net.sockets.DefaultSocketFactory@ad093076
15:50:17,087 INFO [NamingService] Listening on port 1099
15:50:17,107 INFO [NamingService] Started jboss:service=Naming
15:50:17,107 INFO [JNDIView] Started jboss:service=JNDIView
15:50:17,117 INFO [SecurityConfig] Started jboss.security:service=SecurityConfig
15:50:17,227 INFO [XMLLoginConfig] Started jboss.security:service=XMLLoginConfig
15:50:17,257 INFO [JaasSecurityManagerService] Started jboss.security:service=JaasSecurityManager
15:50:17,327 INFO [TransactionManagerService] Started jboss:service=TransactionManager
15:50:17,417 INFO [JRMPInvoker] Started jboss:service=invoker,type=jrmp
15:50:17,497 INFO [JRMPProxyFactory] Started jboss:service=proxyFactory,target=ClientUserTransactionFactory
15:50:17,507 INFO [JRMPProxyFactory] Started jboss:service=proxyFactory,target=ClientUserTransaction
15:50:17,517 INFO [ClientUserTransactionService] Started jboss:service=ClientUserTransaction
15:50:17,527 INFO [LocalInvoker] Started jboss:service=invoker,type=local
15:50:17,567 INFO [PooledInvoker] Started jboss:service=invoker,type=pooled
15:50:17,587 INFO [MainDeployer] Adding deployer: org.jboss.ejb.EJBDeployer@859a68
15:50:17,587 INFO [EJBDeployer] Started jboss.ejb:service=EJBDeployer
15:50:17,607 INFO [MainDeployer] Adding deployer: org.jboss.deployment.EARDeployer@88df60
15:50:17,607 INFO [EARDeployer] Started jboss.j2ee:service=EARDeployer
15:50:17,657 INFO [MainDeployer] Adding deployer: org.jboss.varia.deployment.BeanShellSubDeployer@1490eb5
15:50:17,657 INFO [BeanShellSubDeployer] Started jboss.scripts:service=BSHDeployer
15:50:17,717 INFO [MainDeployer] Starting deployment of package: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/
15:50:17,747 INFO [SARDeployer] nested deployment: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/invoker.war/
15:50:17,798 INFO [MainDeployer] deployment waiting for deployer: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/invoker.w
ar/
15:50:18,118 INFO [HttpInvoker] Started jboss:service=invoker,type=http
15:50:18,138 INFO [HttpInvokerHA] Started jboss:service=invoker,type=httpHA
15:50:18,158 INFO [HttpProxyFactory] Started jboss:service=invoker,type=http,target=Naming
15:50:18,168 INFO [HttpProxyFactory] Started jboss:service=invoker,type=http,target=Naming,readonly=true
15:50:18,288 INFO [MainDeployer] Deployed package: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/
15:50:18,298 INFO [MainDeployer] Starting deployment of package: file:/C:/jboss-3.2.3/server/booker/deploy/jboss-jca.sar
15:50:19,049 INFO [XSLSubDeployer] Created templates: org.apache.xalan.templates.StylesheetRoot@8b8a47
15:50:19,059 INFO [MainDeployer] Adding deployer: org.jboss.resource.RARDeployer@1236cd5
15:50:19,059 INFO [MainDeployer] Starting deployment of package: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/invoker.wa
r/
15:50:19,059 INFO [MainDeployer] deployment waiting for deployer: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/invoker.w
ar/
15:50:19,059 INFO [MainDeployer] Deployment of package: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/invoker.war/ is wai
ting for an appropriate deployer.
15:50:19,059 INFO [RARDeployer] Started jboss.jca:service=RARDeployer
15:50:19,129 INFO [MainDeployer] Adding deployer: org.jboss.deployment.XSLSubDeployer@e41bc3
15:50:19,129 INFO [MainDeployer] Starting deployment of package: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/invoker.wa
r/
15:50:19,129 INFO [MainDeployer] deployment waiting for deployer: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/invoker.w
ar/
15:50:19,200 INFO [MainDeployer] Deployment of package: file:/C:/jboss-3.2.3/server/booker/deploy/http-invoker.sar/invoker.war/ is wai
ting for an appropriate deployer.
15:50:19,200 INFO [XSLSubDeployer] Started jboss.jca:service=ConnectionFactoryDeployer
15:50:19,200 INFO [JMSAppenderDelegate] /config/JMSAppenderConfig.xml
15:50:19,260 INFO [JMSAppenderDelegate] Configuring from: jar:file:/C:/jboss-3.2.3/server/booker/lib/logdelegate.jar!/config/JMSAppend
erConfig.xml

And it hangs here...

Topic "eventLogging" is created within JBossMQ.
I am using JBoss 3.2.3 default server instance, Windows 2000 and j2sdk1.4.2_05.

Anybody knows what is the issue here?

Thanks in advance.

cheers,

Marcin

ps. sorry for this post being so long ;-)

[genman]

DOMConfigurator.configure(config);

This will blow away any existing log configuration you're doing, causing all the logging to apparently stop.

What you should do is create an Appender, add it to the root category (LoggergetRootLogger().addAppender) rather than call the DOMConfiguratator.

Check for hangs using CTRL-\ or CTRL-BREAK, not your log output.

[mkania]

thanks mate!
it helped, jboss doesn't stop any more.

I have changed the JMSAppender configuration stuff to:

 private void loadLog4JConfig() {
 try {

 log.info("configuring a JMSAppender");
 JMSAppender allEventsJMSAppender = new JMSAppender();
 allEventsJMSAppender.setInitialContextFactoryName("org.jnp.interfaces.NamingContextFactory");
 allEventsJMSAppender.setProviderURL("jnp://localhost:1099");
 allEventsJMSAppender.setURLPkgPrefixes("org.jboss.naming:org.jnp.interfaces");
 allEventsJMSAppender.setTopicConnectionFactoryBindingName("ConnectionFactory");
 allEventsJMSAppender.setTopicBindingName("topic/eventLogging");
 allEventsJMSAppender.setUserName("logger");
 allEventsJMSAppender.setPassword("logger");
 allEventsJMSAppender.setLocationInfo(true);
 allEventsJMSAppender.setName("allEventsJMSAppender");

 allEventsJMSAppender.activateOptions();

 Logger root = Logger.getRootLogger();
 root.addAppender(allEventsJMSAppender);

 // some info stuff
 log.info(root.getLevel());
 log.info(root.getName());
 Enumeration appenders = root.getAllAppenders();
 while(appenders.hasMoreElements()) {
 Appender appender = (Appender) appenders.nextElement();
 log.info(appender.getName());
 }

 } catch (Exception e) {
 log.error("Failed to load log4j config", e);
 }
 }

Unfortunately Jboss still doesn't send logs to an appropriate JMS topic.

JBoss log4j configuration file is following:

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

 <appender name="FILE" class="org.jboss.logging.appender.DailyRollingFileAppender">
 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
 <param name="File" value="${jboss.server.home.dir}/log/server.log"/>
 <param name="Append" value="false"/>
 <param name="DatePattern" value="'.'yyyy-MM-dd"/>
 <layout class="org.apache.log4j.PatternLayout">
 <param name="ConversionPattern" value="%d %-5p [%c] %m%n"/>
 </layout>
 </appender>

 <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
 <param name="Target" value="System.out"/>
 <param name="Threshold" value="INFO"/>

 <layout class="org.apache.log4j.PatternLayout">
 <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}] %m%n"/>
 </layout>
 </appender>

 <appender name="JSR77" class="org.apache.log4j.FileAppender">
 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
 <param name="Append" value="false"/>
 <param name="File" value="${jboss.server.home.dir}/log/jsr77.log"/>
 <layout class="org.apache.log4j.PatternLayout">
 <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}] %m%n"/>
 </layout>
 </appender>

 <!-- Limit the org.apache.commons category to INFO as its DEBUG is verbose -->
 <category name="org.apache.commons">
 <priority value="INFO"/>
 </category>

 <!-- Limit JBoss categories to INFO -->
 <category name="org.jboss">
 <priority value="DEBUG"/>
 </category>

 <!-- ======================= -->
 <!-- Setup the Root category -->
 <!-- ======================= -->
 <root>
 <appender-ref ref="CONSOLE"/>
 <appender-ref ref="FILE"/>
 </root>

</log4j:configuration>

I added some info stuff in the method above to let me know what was happening. Console says:

12:02:10,019 INFO [JMSAppenderDelegate] configuring a JMSAppender
12:02:10,279 INFO [JMSAppenderDelegate] DEBUG
12:02:10,279 INFO [JMSAppenderDelegate] root
12:02:10,289 INFO [JMSAppenderDelegate] CONSOLE
12:02:10,289 INFO [JMSAppenderDelegate] FILE
12:02:10,289 INFO [JMSAppenderDelegate] allEventsJMSAppender
12:02:10,289 INFO [JMSAppenderDelegate] JMSAppenderDelegate service started
12:02:10,289 INFO [JMSAppenderDelegate] Started booker.logdelegate:service=JMSAppenderDelegate

Please correct me if I am wrong. It means that my appender has been added and now the root category has three appenders, one for console, second for a file and mine. Default level is DEBUG. So all the jboss logs should go to all configured appenders, in my case to three of them. Levels also should be ok. But the topic associated with this JMSAppender doesn't get any of them.

Anybody knows what is wrong?

Sorry for the trouble and thanks in advance.

cheers,

m.