Jboss Logging with SLF4J in EJB : breaks logging
zecas Mar 23, 2011 2:33 PMHi,
I'm having some difficulties putting SLF4J working with a simple EAR project, specifically when it is a dependency of an EJB.
This is getting serious, as I can't continue development much further, and I'm getting frustrated with this JBoss/SLF4J/Logback ... so I'm looking for some help over here, I hope someone can give me a light on the subject.
I'm running JBoss 5.1.0 GA out of the box, and I deploy the EAR just copying the EAR file to "...\jboss-5.1.0.GA\server\default". My JDK is version 1.6.0_21. Maven version is 2.2.1 (r801777; 2009-08-06 20:16:01+0100).
My project modules are stored in "C:\test\...", and the log file is defined in "logback.xml" to be "C:\test\mylog.log". Sources are attached.
Building the project package using maven ("C:\test\myproject>mvn clean package") will give me the following project structure:
[ myear-1.0.0.ear ] | | logback-classic-0.9.26.jar | logback-core-0.9.26.jar | slf4j-api-1.6.1.jar | +---META-INF | application.xml | MANIFEST.MF | > (file content:) | > Manifest-Version: 1.0 | > Archiver-Version: Plexus Archiver | > Created-By: Apache Maven | > Built-By: username | > Build-Jdk: 1.6.0_21 | +---myejb-1.0.0-client.jar | | logback.xml | | | +---com | | \---test | | ProcessorBeanLocal.class | | ProcessorBeanRemote.class | | | \---META-INF | MANIFEST.MF | > (file content:) | > Manifest-Version: 1.0 | > Archiver-Version: Plexus Archiver | > Created-By: Apache Maven | > Built-By: username | > Build-Jdk: 1.6.0_21 | +---myejb-1.0.0.jar | | logback.xml | | | +---com | | \---test | | ProcessorBean.class | | ProcessorBeanLocal.class | | ProcessorBeanRemote.class | | | \---META-INF | MANIFEST.MF | > (file content:) | > Manifest-Version: 1.0 | > Archiver-Version: Plexus Archiver | > Created-By: Apache Maven | > Built-By: username | > Build-Jdk: 1.6.0_21 | \---myweb-1.0.0.war +---META-INF | MANIFEST.MF | > (file content:) | > Manifest-Version: 1.0 | > Archiver-Version: Plexus Archiver | > Created-By: Apache Maven | > Built-By: username | > Build-Jdk: 1.6.0_21 | > Class-Path: myejb-1.0.0-client.jar logback-classic-0.9.26.jar logback- | > core-0.9.26.jar slf4j-api-1.6.1.jar | \---WEB-INF | web.xml | +---classes | \---com | \---test | MyListener.class | \---lib
The project is constructed as follows:
The WAR has EJB dependency, and a listener. The listener only does one thing, log a line using SLF4J and Logback. The logback definition is "logback.xml" and is included in the EJB.
Since the WAR can access EJB contents, it all works fine. At this time, EJB does not use any SLF4J for logging.
The Problem:
Now what I want, is to use SLF4J in EJB ... for that, I start with one small step ... to include the SLF4J dependency on EJB. I don't do anything else, I just uncomment the dependency in "pom.xml" of the EJB, and it just get's added to the Class-Path entry in MANIFEST.MF of the EJB.
The minute I do it, the logging breaks. The listener doesn't log anymore, I do believe that the SLF4J just fails to find the logback.xml definition, so it loads a basic definition that just throws every log message to stdout, as I can see the messages on server.log, and in the console.
So before doing even the smallest change in code, I'm not able to do any logging in my application.
I need it badly, and this is just keeping me from moving forward in development, and I'm looking as time is flying ...
Need some help, seriously.
System log when everything goes well:
2011-03-23 16:52:28,430 INFO [org.jboss.web.WebService] (main) Using RMI server codebase: http://127.0.0.1:8083/ 2011-03-23 16:52:31,883 INFO [org.jboss.wsf.stack.jbws.NativeServerConfig] (main) JBoss Web Services - Stack Native Core 2011-03-23 16:52:31,899 INFO [org.jboss.wsf.stack.jbws.NativeServerConfig] (main) 3.1.2.GA 2011-03-23 16:52:32,352 INFO [org.jboss.dependency.plugins.AttributeCallbackItem] (main) Owner callback not implemented. 2011-03-23 16:52:33,008 INFO [org.jboss.logbridge.LogNotificationListener] (main) Adding notification listener for logging mbean "jboss.system:service=Logging,type=Log4jService" to server org.jboss.mx.server.MBeanServerImpl@1fb050c[ defaultDomain='jboss' ] 2011-03-23 16:52:40,243 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@18635696{vfsfile:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/profileservice-secured.jar/} 2011-03-23 16:52:40,243 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@18635696{vfsfile:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/profileservice-secured.jar/} 2011-03-23 16:52:40,243 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@18635696{vfsfile:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/profileservice-secured.jar/} 2011-03-23 16:52:40,243 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@18635696{vfsfile:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/profileservice-secured.jar/} 2011-03-23 16:52:40,258 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@5125095{vfszip:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/myear-1.0.0.ear/myejb-1.0.0.jar/} 2011-03-23 16:52:40,258 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@5125095{vfszip:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/myear-1.0.0.ear/myejb-1.0.0.jar/} 2011-03-23 16:52:42,274 INFO [org.jboss.mx.remoting.service.JMXConnectorServerService] (main) JMX Connector server: service:jmx:rmi://127.0.0.1/jndi/rmi://127.0.0.1:1090/jmxconnector 2011-03-23 16:52:42,337 INFO [org.jboss.mail.MailService] (main) Mail Service bound to java:/Mail 2011-03-23 16:52:43,415 WARN [org.jboss.jms.server.jbosssx.JBossASSecurityMetadataStore] (main) WARNING! POTENTIAL SECURITY RISK. It has been detected that the MessageSucker component which sucks messages from one node to another has not had its password changed from the installation default. Please see the JBoss Messaging user guide for instructions on how to do this. 2011-03-23 16:52:43,446 WARN [org.jboss.annotation.factory.AnnotationCreator] (main) No ClassLoader provided, using TCCL: org.jboss.managed.api.annotation.ManagementComponent 2011-03-23 16:52:43,493 WARN [org.jboss.annotation.factory.AnnotationCreator] (main) No ClassLoader provided, using TCCL: org.jboss.managed.api.annotation.ManagementComponent 2011-03-23 16:52:43,540 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) JBossTS Transaction Service (JTA version - tag:JBOSSTS_4_6_1_GA) - JBoss Inc. 2011-03-23 16:52:43,540 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Setting up property manager MBean and JMX layer 2011-03-23 16:52:43,680 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Initializing recovery manager 2011-03-23 16:52:43,821 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Recovery manager configured 2011-03-23 16:52:43,821 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Binding TransactionManager JNDI Reference 2011-03-23 16:52:43,837 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Starting transaction recovery manager 2011-03-23 16:52:44,087 INFO [org.apache.catalina.core.AprLifecycleListener] (main) The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jdk1.6.0_21\bin;.;C:\WINDOWS\Sun\Java\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\IBM\Personal Communications\;C:\Program Files\IBM\Trace Facility\;C:\Program Files\Windows Imaging\;C:\WINDOWS\system32\WindowsPowerShell\v1.0;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\IBM\Personal Communications\;C:\Program Files\IBM\Trace Facility\;C:\Program Files\Windows Imaging\;C:\WINDOWS\system32\WindowsPowerShell\v1.0;C:\Program Files\Java\apache-ant-1.8.1\bin;C:\Program Files\Java\apache-maven-2.2.1\bin;C:\Program Files\mysql-5.1.48-win32\bin;C:\Program Files\unx_utils;C:\Program Files\junction 2011-03-23 16:52:44,118 INFO [org.apache.coyote.http11.Http11Protocol] (main) Initializing Coyote HTTP/1.1 on http-127.0.0.1-8080 2011-03-23 16:52:44,133 INFO [org.apache.coyote.ajp.AjpProtocol] (main) Initializing Coyote AJP/1.3 on ajp-127.0.0.1-8009 2011-03-23 16:52:44,133 INFO [org.apache.catalina.core.StandardService] (main) Starting service jboss.web 2011-03-23 16:52:44,133 INFO [org.apache.catalina.core.StandardEngine] (main) Starting Servlet Engine: JBoss Web/2.1.3.GA 2011-03-23 16:52:44,165 INFO [org.apache.catalina.startup.Catalina] (main) Server startup in 38 ms 2011-03-23 16:52:44,180 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/invoker 2011-03-23 16:52:44,555 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/jbossws 2011-03-23 16:52:44,571 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/web-console 2011-03-23 16:52:44,758 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/jboss-local-jdbc.rar/META-INF/ra.xml 2011-03-23 16:52:44,774 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/jboss-xa-jdbc.rar/META-INF/ra.xml 2011-03-23 16:52:44,790 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/jms-ra.rar/META-INF/ra.xml 2011-03-23 16:52:44,805 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/mail-ra.rar/META-INF/ra.xml 2011-03-23 16:52:44,805 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/quartz-ra.rar/META-INF/ra.xml 2011-03-23 16:52:44,852 INFO [org.quartz.simpl.SimpleThreadPool] (main) Job execution threads will use class loader of thread: main 2011-03-23 16:52:44,868 INFO [org.quartz.core.QuartzScheduler] (main) Quartz Scheduler v.1.5.2 created. 2011-03-23 16:52:44,868 INFO [org.quartz.simpl.RAMJobStore] (main) RAMJobStore initialized. 2011-03-23 16:52:44,868 INFO [org.quartz.impl.StdSchedulerFactory] (main) Quartz scheduler 'DefaultQuartzScheduler' initialized from default resource file in Quartz package: 'quartz.properties' 2011-03-23 16:52:44,868 INFO [org.quartz.impl.StdSchedulerFactory] (main) Quartz scheduler version: 1.5.2 2011-03-23 16:52:44,868 INFO [org.quartz.core.QuartzScheduler] (main) Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED started. 2011-03-23 16:52:45,212 INFO [org.jboss.resource.connectionmanager.ConnectionFactoryBindingService] (main) Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=DefaultDS' to JNDI name 'java:DefaultDS' 2011-03-23 16:52:45,462 INFO [org.jboss.jms.server.ServerPeer] (main) JBoss Messaging 1.4.3.GA server [0] started 2011-03-23 16:52:45,524 INFO [org.jboss.jms.server.destination.QueueService] (main) Queue[MyIN, name=MyInput] started, fullSize=200000, pageSize=2000, downCacheSize=2000 2011-03-23 16:52:45,524 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactoryJNDIMapper] (main) supportsFailover attribute is true on connection factory: jboss.messaging.connectionfactory:service=ClusteredConnectionFactory but post office is non clustered. So connection factory will *not* support failover 2011-03-23 16:52:45,524 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactoryJNDIMapper] (main) supportsLoadBalancing attribute is true on connection factory: jboss.messaging.connectionfactory:service=ClusteredConnectionFactory but post office is non clustered. So connection factory will *not* support load balancing 2011-03-23 16:52:45,555 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) Connector bisocket://127.0.0.1:4457 has leasing enabled, lease period 10000 milliseconds 2011-03-23 16:52:45,555 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) org.jboss.jms.server.connectionfactory.ConnectionFactory@191a87d started 2011-03-23 16:52:45,555 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) Connector bisocket://127.0.0.1:4457 has leasing enabled, lease period 10000 milliseconds 2011-03-23 16:52:45,555 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) org.jboss.jms.server.connectionfactory.ConnectionFactory@e4fc96 started 2011-03-23 16:52:45,555 INFO [org.jboss.jms.server.destination.QueueService] (main) Queue[/queue/DLQ] started, fullSize=200000, pageSize=2000, downCacheSize=2000 2011-03-23 16:52:45,555 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) Connector bisocket://127.0.0.1:4457 has leasing enabled, lease period 10000 milliseconds 2011-03-23 16:52:45,555 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) org.jboss.jms.server.connectionfactory.ConnectionFactory@182b0c8 started 2011-03-23 16:52:45,555 INFO [org.jboss.jms.server.destination.QueueService] (main) Queue[/queue/ExpiryQueue] started, fullSize=200000, pageSize=2000, downCacheSize=2000 2011-03-23 16:52:45,618 INFO [org.jboss.resource.connectionmanager.ConnectionFactoryBindingService] (main) Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name=JmsXA' to JNDI name 'java:JmsXA' 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Created KernelDeployment for: profileservice-secured.jar 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) installing bean: jboss.j2ee:jar=profileservice-secured.jar,name=SecureProfileService,service=EJB3 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) with dependencies: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and demands: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureManagementView/remote-org.jboss.deployers.spi.management.ManagementView 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jboss.ejb:service=EJBTimerService 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and supplies: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:org.jboss.profileservice.spi.ProfileService 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureProfileService/remote 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureProfileService/remote-org.jboss.profileservice.spi.ProfileService 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Added bean(jboss.j2ee:jar=profileservice-secured.jar,name=SecureProfileService,service=EJB3) to KernelDeployment of: profileservice-secured.jar 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) installing bean: jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) with dependencies: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and demands: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jboss.ejb:service=EJBTimerService 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and supplies: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureDeploymentManager/remote-org.jboss.deployers.spi.management.deploy.DeploymentManager 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:org.jboss.deployers.spi.management.deploy.DeploymentManager 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureDeploymentManager/remote 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Added bean(jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3) to KernelDeployment of: profileservice-secured.jar 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) installing bean: jboss.j2ee:jar=profileservice-secured.jar,name=SecureManagementView,service=EJB3 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) with dependencies: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and demands: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jboss.ejb:service=EJBTimerService 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and supplies: 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureManagementView/remote-org.jboss.deployers.spi.management.ManagementView 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:org.jboss.deployers.spi.management.ManagementView 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureManagementView/remote 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Added bean(jboss.j2ee:jar=profileservice-secured.jar,name=SecureManagementView,service=EJB3) to KernelDeployment of: profileservice-secured.jar 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.endpoint.deployers.EJB3EndpointDeployer] (main) Deploy AbstractBeanMetaData@d4bc7{name=jboss.j2ee:jar=profileservice-secured.jar,name=SecureProfileService,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true} 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.endpoint.deployers.EJB3EndpointDeployer] (main) Deploy AbstractBeanMetaData@109f88f{name=jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true} 2011-03-23 16:52:45,821 INFO [org.jboss.ejb3.endpoint.deployers.EJB3EndpointDeployer] (main) Deploy AbstractBeanMetaData@1be1aa0{name=jboss.j2ee:jar=profileservice-secured.jar,name=SecureManagementView,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true} 2011-03-23 16:52:45,883 INFO [org.jboss.ejb3.session.SessionSpecContainer] (main) Starting jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3 2011-03-23 16:52:45,883 INFO [org.jboss.ejb3.EJBContainer] (main) STARTED EJB: org.jboss.profileservice.ejb.SecureDeploymentManager ejbName: SecureDeploymentManager 2011-03-23 16:52:46,024 INFO [org.jboss.ejb3.proxy.impl.jndiregistrar.JndiSessionRegistrarBase] (main) Binding the following Entries in Global JNDI: SecureDeploymentManager/remote - EJB3.x Default Remote Business Interface SecureDeploymentManager/remote-org.jboss.deployers.spi.management.deploy.DeploymentManager - EJB3.x Remote Business Interface 2011-03-23 16:52:46,087 INFO [org.jboss.ejb3.session.SessionSpecContainer] (main) Starting jboss.j2ee:jar=profileservice-secured.jar,name=SecureManagementView,service=EJB3 2011-03-23 16:52:46,102 INFO [org.jboss.ejb3.EJBContainer] (main) STARTED EJB: org.jboss.profileservice.ejb.SecureManagementView ejbName: SecureManagementView 2011-03-23 16:52:46,102 INFO [org.jboss.ejb3.proxy.impl.jndiregistrar.JndiSessionRegistrarBase] (main) Binding the following Entries in Global JNDI: SecureManagementView/remote - EJB3.x Default Remote Business Interface SecureManagementView/remote-org.jboss.deployers.spi.management.ManagementView - EJB3.x Remote Business Interface 2011-03-23 16:52:46,133 INFO [org.jboss.ejb3.session.SessionSpecContainer] (main) Starting jboss.j2ee:jar=profileservice-secured.jar,name=SecureProfileService,service=EJB3 2011-03-23 16:52:46,133 INFO [org.jboss.ejb3.EJBContainer] (main) STARTED EJB: org.jboss.profileservice.ejb.SecureProfileServiceBean ejbName: SecureProfileService 2011-03-23 16:52:46,133 INFO [org.jboss.ejb3.proxy.impl.jndiregistrar.JndiSessionRegistrarBase] (main) Binding the following Entries in Global JNDI: SecureProfileService/remote - EJB3.x Default Remote Business Interface SecureProfileService/remote-org.jboss.profileservice.spi.ProfileService - EJB3.x Remote Business Interface 2011-03-23 16:52:46,258 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/admin-console 2011-03-23 16:52:46,305 INFO [javax.enterprise.resource.webcontainer.jsf.config] (main) Initializing Mojarra (1.2_12-b01-FCS) for context '/admin-console' 2011-03-23 16:52:47,727 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/ 2011-03-23 16:52:47,774 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/jmx-console 2011-03-23 16:52:47,915 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/monitor 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Created KernelDeployment for: myejb-1.0.0.jar 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) installing bean: jboss.j2ee:ear=myear-1.0.0.ear,jar=myejb-1.0.0.jar,name=my-processor,service=EJB3 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) with dependencies: 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and demands: 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jboss.ejb:service=EJBTimerService 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and supplies: 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:myear-1.0.0/my-processor/remote-com.test.ProcessorBeanRemote 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:myear-1.0.0/my-processor/local 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:com.test.ProcessorBeanRemote 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:com.test.ProcessorBeanLocal 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:myear-1.0.0/my-processor/remote 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:myear-1.0.0/my-processor/local-com.test.ProcessorBeanLocal 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Added bean(jboss.j2ee:ear=myear-1.0.0.ear,jar=myejb-1.0.0.jar,name=my-processor,service=EJB3) to KernelDeployment of: myejb-1.0.0.jar 2011-03-23 16:52:47,946 INFO [org.jboss.ejb3.endpoint.deployers.EJB3EndpointDeployer] (main) Deploy AbstractBeanMetaData@1b3e8b0{name=jboss.j2ee:ear=myear-1.0.0.ear,jar=myejb-1.0.0.jar,name=my-processor,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true} 2011-03-23 16:52:48,071 INFO [org.jboss.ejb3.session.SessionSpecContainer] (main) Starting jboss.j2ee:ear=myear-1.0.0.ear,jar=myejb-1.0.0.jar,name=my-processor,service=EJB3 2011-03-23 16:52:48,071 INFO [org.jboss.ejb3.EJBContainer] (main) STARTED EJB: com.test.ProcessorBean ejbName: my-processor 2011-03-23 16:52:48,087 INFO [org.jboss.ejb3.proxy.impl.jndiregistrar.JndiSessionRegistrarBase] (main) Binding the following Entries in Global JNDI: myear-1.0.0/my-processor/remote - EJB3.x Default Remote Business Interface myear-1.0.0/my-processor/remote-com.test.ProcessorBeanRemote - EJB3.x Remote Business Interface myear-1.0.0/my-processor/local - EJB3.x Default Local Business Interface myear-1.0.0/my-processor/local-com.test.ProcessorBeanLocal - EJB3.x Local Business Interface 2011-03-23 16:52:48,243 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/myweb 2011-03-23 16:52:48,290 ERROR [STDERR] (main) SLF4J: Class path contains multiple SLF4J bindings. 2011-03-23 16:52:48,290 ERROR [STDERR] (main) SLF4J: Found binding in [vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/myear-1.0.0.ear/logback-classic-0.9.26.jar/org/slf4j/impl/StaticLoggerBinder.class] 2011-03-23 16:52:48,290 ERROR [STDERR] (main) SLF4J: Found binding in [vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/common/lib/slf4j-jboss-logging.jar/org/slf4j/impl/StaticLoggerBinder.class] 2011-03-23 16:52:48,290 ERROR [STDERR] (main) SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2011-03-23 16:52:48,383 INFO [STDOUT] (main) 16:52:48,305 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 16:52:48,305 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 16:52:48,305 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/myear-1.0.0.ear/myejb-1.0.0-client.jar/logback.xml] 16:52:48,305 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs multiple times on the classpath. 16:52:48,305 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/myear-1.0.0.ear/myejb-1.0.0-client.jar/logback.xml] 16:52:48,305 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/myear-1.0.0.ear/myejb-1.0.0.jar/logback.xml] 16:52:48,352 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set 16:52:48,352 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 16:52:48,352 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE] 16:52:48,352 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 16:52:48,383 |-INFO in ch.qos.logback.core.FileAppender[FILE] - File property is set to [/test/mylog.log] 16:52:48,383 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [mylogger] to DEBUG 16:52:48,383 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [mylogger] to true 16:52:48,383 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG 16:52:48,383 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT] 2011-03-23 16:52:48,415 WARN [org.jboss.ejb3.interceptors.aop.InterceptorsFactory] (main) EJBTHREE-1246: Do not use InterceptorsFactory with a ManagedObjectAdvisor, InterceptorRegistry should be used via the bean container 2011-03-23 16:52:48,415 WARN [org.jboss.ejb3.interceptors.aop.InterceptorsFactory] (main) EJBTHREE-1246: Do not use InterceptorsFactory with a ManagedObjectAdvisor, InterceptorRegistry should be used via the bean container 2011-03-23 16:52:48,415 INFO [STDOUT] (main) Entered EJB log [Message!] 2011-03-23 16:52:48,446 INFO [org.apache.coyote.http11.Http11Protocol] (main) Starting Coyote HTTP/1.1 on http-127.0.0.1-8080 2011-03-23 16:52:48,462 INFO [org.apache.coyote.ajp.AjpProtocol] (main) Starting Coyote AJP/1.3 on ajp-127.0.0.1-8009 2011-03-23 16:52:48,462 INFO [org.jboss.bootstrap.microcontainer.ServerImpl] (main) JBoss (Microcontainer) [5.1.0.GA (build: SVNTag=JBoss_5_1_0_GA date=200905221634)] Started in 23s:938ms
The following line is added to c:\test\mylog.log, as expected:
2011-03-23 16:52:48.383 : [mylogger] INFO : ProcessorBeanLocal INJECTED!
System log when goes wrong (SLF4J dependency added to EJB):
2011-03-23 17:14:37,899 INFO [org.jboss.web.WebService] (main) Using RMI server codebase: http://127.0.0.1:8083/ 2011-03-23 17:14:41,165 INFO [org.jboss.wsf.stack.jbws.NativeServerConfig] (main) JBoss Web Services - Stack Native Core 2011-03-23 17:14:41,165 INFO [org.jboss.wsf.stack.jbws.NativeServerConfig] (main) 3.1.2.GA 2011-03-23 17:14:41,524 INFO [org.jboss.dependency.plugins.AttributeCallbackItem] (main) Owner callback not implemented. 2011-03-23 17:14:42,165 INFO [org.jboss.logbridge.LogNotificationListener] (main) Adding notification listener for logging mbean "jboss.system:service=Logging,type=Log4jService" to server org.jboss.mx.server.MBeanServerImpl@1088a1b[ defaultDomain='jboss' ] 2011-03-23 17:14:49,133 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@8316706{vfsfile:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/profileservice-secured.jar/} 2011-03-23 17:14:49,133 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@8316706{vfsfile:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/profileservice-secured.jar/} 2011-03-23 17:14:49,133 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@8316706{vfsfile:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/profileservice-secured.jar/} 2011-03-23 17:14:49,133 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@8316706{vfsfile:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/profileservice-secured.jar/} 2011-03-23 17:14:49,149 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@13703190{vfszip:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/myear-1.0.0.ear/myejb-1.0.0.jar/} 2011-03-23 17:14:49,149 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] (main) Encountered deployment AbstractVFSDeploymentContext@13703190{vfszip:/C:/Program%20Files/Java/jboss-5.1.0.GA/server/default/deploy/myear-1.0.0.ear/myejb-1.0.0.jar/} 2011-03-23 17:14:51,180 INFO [org.jboss.mx.remoting.service.JMXConnectorServerService] (main) JMX Connector server: service:jmx:rmi://127.0.0.1/jndi/rmi://127.0.0.1:1090/jmxconnector 2011-03-23 17:14:51,243 INFO [org.jboss.mail.MailService] (main) Mail Service bound to java:/Mail 2011-03-23 17:14:52,415 WARN [org.jboss.jms.server.jbosssx.JBossASSecurityMetadataStore] (main) WARNING! POTENTIAL SECURITY RISK. It has been detected that the MessageSucker component which sucks messages from one node to another has not had its password changed from the installation default. Please see the JBoss Messaging user guide for instructions on how to do this. 2011-03-23 17:14:52,415 WARN [org.jboss.annotation.factory.AnnotationCreator] (main) No ClassLoader provided, using TCCL: org.jboss.managed.api.annotation.ManagementComponent 2011-03-23 17:14:52,462 WARN [org.jboss.annotation.factory.AnnotationCreator] (main) No ClassLoader provided, using TCCL: org.jboss.managed.api.annotation.ManagementComponent 2011-03-23 17:14:52,493 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) JBossTS Transaction Service (JTA version - tag:JBOSSTS_4_6_1_GA) - JBoss Inc. 2011-03-23 17:14:52,493 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Setting up property manager MBean and JMX layer 2011-03-23 17:14:52,633 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Initializing recovery manager 2011-03-23 17:14:52,727 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Recovery manager configured 2011-03-23 17:14:52,727 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Binding TransactionManager JNDI Reference 2011-03-23 17:14:52,743 INFO [com.arjuna.ats.jbossatx.jta.TransactionManagerService] (main) Starting transaction recovery manager 2011-03-23 17:14:52,977 INFO [org.apache.catalina.core.AprLifecycleListener] (main) The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jdk1.6.0_21\bin;.;C:\WINDOWS\Sun\Java\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\IBM\Personal Communications\;C:\Program Files\IBM\Trace Facility\;C:\Program Files\Windows Imaging\;C:\WINDOWS\system32\WindowsPowerShell\v1.0;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\IBM\Personal Communications\;C:\Program Files\IBM\Trace Facility\;C:\Program Files\Windows Imaging\;C:\WINDOWS\system32\WindowsPowerShell\v1.0;C:\Program Files\Java\apache-ant-1.8.1\bin;C:\Program Files\Java\apache-maven-2.2.1\bin;C:\Program Files\mysql-5.1.48-win32\bin;C:\Program Files\unx_utils;C:\Program Files\junction 2011-03-23 17:14:53,008 INFO [org.apache.coyote.http11.Http11Protocol] (main) Initializing Coyote HTTP/1.1 on http-127.0.0.1-8080 2011-03-23 17:14:53,008 INFO [org.apache.coyote.ajp.AjpProtocol] (main) Initializing Coyote AJP/1.3 on ajp-127.0.0.1-8009 2011-03-23 17:14:53,024 INFO [org.apache.catalina.core.StandardService] (main) Starting service jboss.web 2011-03-23 17:14:53,024 INFO [org.apache.catalina.core.StandardEngine] (main) Starting Servlet Engine: JBoss Web/2.1.3.GA 2011-03-23 17:14:53,055 INFO [org.apache.catalina.startup.Catalina] (main) Server startup in 39 ms 2011-03-23 17:14:53,055 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/web-console 2011-03-23 17:14:53,555 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/jbossws 2011-03-23 17:14:53,571 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/invoker 2011-03-23 17:14:53,649 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/jboss-local-jdbc.rar/META-INF/ra.xml 2011-03-23 17:14:53,665 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/jboss-xa-jdbc.rar/META-INF/ra.xml 2011-03-23 17:14:53,680 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/jms-ra.rar/META-INF/ra.xml 2011-03-23 17:14:53,696 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/mail-ra.rar/META-INF/ra.xml 2011-03-23 17:14:53,712 INFO [org.jboss.resource.deployers.RARDeployment] (main) Required license terms exist, view vfszip:/C:/Program Files/Java/jboss-5.1.0.GA/server/default/deploy/quartz-ra.rar/META-INF/ra.xml 2011-03-23 17:14:53,743 INFO [org.quartz.simpl.SimpleThreadPool] (main) Job execution threads will use class loader of thread: main 2011-03-23 17:14:53,758 INFO [org.quartz.core.QuartzScheduler] (main) Quartz Scheduler v.1.5.2 created. 2011-03-23 17:14:53,758 INFO [org.quartz.simpl.RAMJobStore] (main) RAMJobStore initialized. 2011-03-23 17:14:53,758 INFO [org.quartz.impl.StdSchedulerFactory] (main) Quartz scheduler 'DefaultQuartzScheduler' initialized from default resource file in Quartz package: 'quartz.properties' 2011-03-23 17:14:53,758 INFO [org.quartz.impl.StdSchedulerFactory] (main) Quartz scheduler version: 1.5.2 2011-03-23 17:14:53,758 INFO [org.quartz.core.QuartzScheduler] (main) Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED started. 2011-03-23 17:14:54,055 INFO [org.jboss.resource.connectionmanager.ConnectionFactoryBindingService] (main) Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=DefaultDS' to JNDI name 'java:DefaultDS' 2011-03-23 17:14:54,305 INFO [org.jboss.jms.server.ServerPeer] (main) JBoss Messaging 1.4.3.GA server [0] started 2011-03-23 17:14:54,352 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactoryJNDIMapper] (main) supportsFailover attribute is true on connection factory: jboss.messaging.connectionfactory:service=ClusteredConnectionFactory but post office is non clustered. So connection factory will *not* support failover 2011-03-23 17:14:54,352 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactoryJNDIMapper] (main) supportsLoadBalancing attribute is true on connection factory: jboss.messaging.connectionfactory:service=ClusteredConnectionFactory but post office is non clustered. So connection factory will *not* support load balancing 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) Connector bisocket://127.0.0.1:4457 has leasing enabled, lease period 10000 milliseconds 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) org.jboss.jms.server.connectionfactory.ConnectionFactory@546ab2 started 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) Connector bisocket://127.0.0.1:4457 has leasing enabled, lease period 10000 milliseconds 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) org.jboss.jms.server.connectionfactory.ConnectionFactory@b8ce34 started 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) Connector bisocket://127.0.0.1:4457 has leasing enabled, lease period 10000 milliseconds 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.connectionfactory.ConnectionFactory] (main) org.jboss.jms.server.connectionfactory.ConnectionFactory@742ce7 started 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.destination.QueueService] (main) Queue[/queue/ExpiryQueue] started, fullSize=200000, pageSize=2000, downCacheSize=2000 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.destination.QueueService] (main) Queue[MyIN, name=MyInput] started, fullSize=200000, pageSize=2000, downCacheSize=2000 2011-03-23 17:14:54,383 INFO [org.jboss.jms.server.destination.QueueService] (main) Queue[/queue/DLQ] started, fullSize=200000, pageSize=2000, downCacheSize=2000 2011-03-23 17:14:54,430 INFO [org.jboss.resource.connectionmanager.ConnectionFactoryBindingService] (main) Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name=JmsXA' to JNDI name 'java:JmsXA' 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Created KernelDeployment for: profileservice-secured.jar 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) installing bean: jboss.j2ee:jar=profileservice-secured.jar,name=SecureProfileService,service=EJB3 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) with dependencies: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and demands: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureManagementView/remote-org.jboss.deployers.spi.management.ManagementView 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jboss.ejb:service=EJBTimerService 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and supplies: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:org.jboss.profileservice.spi.ProfileService 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureProfileService/remote 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureProfileService/remote-org.jboss.profileservice.spi.ProfileService 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Added bean(jboss.j2ee:jar=profileservice-secured.jar,name=SecureProfileService,service=EJB3) to KernelDeployment of: profileservice-secured.jar 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) installing bean: jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) with dependencies: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and demands: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jboss.ejb:service=EJBTimerService 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and supplies: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureDeploymentManager/remote-org.jboss.deployers.spi.management.deploy.DeploymentManager 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:org.jboss.deployers.spi.management.deploy.DeploymentManager 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureDeploymentManager/remote 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Added bean(jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3) to KernelDeployment of: profileservice-secured.jar 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) installing bean: jboss.j2ee:jar=profileservice-secured.jar,name=SecureManagementView,service=EJB3 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) with dependencies: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and demands: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jboss.ejb:service=EJBTimerService 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and supplies: 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureManagementView/remote-org.jboss.deployers.spi.management.ManagementView 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:org.jboss.deployers.spi.management.ManagementView 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:SecureManagementView/remote 2011-03-23 17:14:54,665 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Added bean(jboss.j2ee:jar=profileservice-secured.jar,name=SecureManagementView,service=EJB3) to KernelDeployment of: profileservice-secured.jar 2011-03-23 17:14:54,680 INFO [org.jboss.ejb3.endpoint.deployers.EJB3EndpointDeployer] (main) Deploy AbstractBeanMetaData@c96a1a{name=jboss.j2ee:jar=profileservice-secured.jar,name=SecureProfileService,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true} 2011-03-23 17:14:54,680 INFO [org.jboss.ejb3.endpoint.deployers.EJB3EndpointDeployer] (main) Deploy AbstractBeanMetaData@39856b{name=jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true} 2011-03-23 17:14:54,680 INFO [org.jboss.ejb3.endpoint.deployers.EJB3EndpointDeployer] (main) Deploy AbstractBeanMetaData@145eca6{name=jboss.j2ee:jar=profileservice-secured.jar,name=SecureManagementView,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true} 2011-03-23 17:14:54,790 INFO [org.jboss.ejb3.session.SessionSpecContainer] (main) Starting jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3 2011-03-23 17:14:54,790 INFO [org.jboss.ejb3.EJBContainer] (main) STARTED EJB: org.jboss.profileservice.ejb.SecureDeploymentManager ejbName: SecureDeploymentManager 2011-03-23 17:14:54,899 INFO [org.jboss.ejb3.proxy.impl.jndiregistrar.JndiSessionRegistrarBase] (main) Binding the following Entries in Global JNDI: SecureDeploymentManager/remote - EJB3.x Default Remote Business Interface SecureDeploymentManager/remote-org.jboss.deployers.spi.management.deploy.DeploymentManager - EJB3.x Remote Business Interface 2011-03-23 17:14:54,946 INFO [org.jboss.ejb3.session.SessionSpecContainer] (main) Starting jboss.j2ee:jar=profileservice-secured.jar,name=SecureManagementView,service=EJB3 2011-03-23 17:14:54,946 INFO [org.jboss.ejb3.EJBContainer] (main) STARTED EJB: org.jboss.profileservice.ejb.SecureManagementView ejbName: SecureManagementView 2011-03-23 17:14:54,946 INFO [org.jboss.ejb3.proxy.impl.jndiregistrar.JndiSessionRegistrarBase] (main) Binding the following Entries in Global JNDI: SecureManagementView/remote - EJB3.x Default Remote Business Interface SecureManagementView/remote-org.jboss.deployers.spi.management.ManagementView - EJB3.x Remote Business Interface 2011-03-23 17:14:54,977 INFO [org.jboss.ejb3.session.SessionSpecContainer] (main) Starting jboss.j2ee:jar=profileservice-secured.jar,name=SecureProfileService,service=EJB3 2011-03-23 17:14:54,977 INFO [org.jboss.ejb3.EJBContainer] (main) STARTED EJB: org.jboss.profileservice.ejb.SecureProfileServiceBean ejbName: SecureProfileService 2011-03-23 17:14:54,977 INFO [org.jboss.ejb3.proxy.impl.jndiregistrar.JndiSessionRegistrarBase] (main) Binding the following Entries in Global JNDI: SecureProfileService/remote - EJB3.x Default Remote Business Interface SecureProfileService/remote-org.jboss.profileservice.spi.ProfileService - EJB3.x Remote Business Interface 2011-03-23 17:14:55,055 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/admin-console 2011-03-23 17:14:55,102 INFO [javax.enterprise.resource.webcontainer.jsf.config] (main) Initializing Mojarra (1.2_12-b01-FCS) for context '/admin-console' 2011-03-23 17:14:56,649 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/ 2011-03-23 17:14:56,758 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/jmx-console 2011-03-23 17:14:56,899 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/monitor 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Created KernelDeployment for: myejb-1.0.0.jar 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) installing bean: jboss.j2ee:ear=myear-1.0.0.ear,jar=myejb-1.0.0.jar,name=my-processor,service=EJB3 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) with dependencies: 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and demands: 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jboss.ejb:service=EJBTimerService 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) and supplies: 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:myear-1.0.0/my-processor/remote-com.test.ProcessorBeanRemote 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:myear-1.0.0/my-processor/local 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:com.test.ProcessorBeanRemote 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Class:com.test.ProcessorBeanLocal 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:myear-1.0.0/my-processor/remote 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) jndi:myear-1.0.0/my-processor/local-com.test.ProcessorBeanLocal 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.deployers.JBossASKernel] (main) Added bean(jboss.j2ee:ear=myear-1.0.0.ear,jar=myejb-1.0.0.jar,name=my-processor,service=EJB3) to KernelDeployment of: myejb-1.0.0.jar 2011-03-23 17:14:56,930 INFO [org.jboss.ejb3.endpoint.deployers.EJB3EndpointDeployer] (main) Deploy AbstractBeanMetaData@6b53e6{name=jboss.j2ee:ear=myear-1.0.0.ear,jar=myejb-1.0.0.jar,name=my-processor,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true} 2011-03-23 17:14:57,040 INFO [org.jboss.ejb3.session.SessionSpecContainer] (main) Starting jboss.j2ee:ear=myear-1.0.0.ear,jar=myejb-1.0.0.jar,name=my-processor,service=EJB3 2011-03-23 17:14:57,040 INFO [org.jboss.ejb3.EJBContainer] (main) STARTED EJB: com.test.ProcessorBean ejbName: my-processor 2011-03-23 17:14:57,243 INFO [org.jboss.ejb3.proxy.impl.jndiregistrar.JndiSessionRegistrarBase] (main) Binding the following Entries in Global JNDI: myear-1.0.0/my-processor/remote - EJB3.x Default Remote Business Interface myear-1.0.0/my-processor/remote-com.test.ProcessorBeanRemote - EJB3.x Remote Business Interface myear-1.0.0/my-processor/local - EJB3.x Default Local Business Interface myear-1.0.0/my-processor/local-com.test.ProcessorBeanLocal - EJB3.x Local Business Interface 2011-03-23 17:14:57,337 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/myweb 2011-03-23 17:14:57,368 INFO [mylogger] (main) ProcessorBeanLocal INJECTED! 2011-03-23 17:14:57,399 WARN [org.jboss.ejb3.interceptors.aop.InterceptorsFactory] (main) EJBTHREE-1246: Do not use InterceptorsFactory with a ManagedObjectAdvisor, InterceptorRegistry should be used via the bean container 2011-03-23 17:14:57,399 WARN [org.jboss.ejb3.interceptors.aop.InterceptorsFactory] (main) EJBTHREE-1246: Do not use InterceptorsFactory with a ManagedObjectAdvisor, InterceptorRegistry should be used via the bean container 2011-03-23 17:14:57,399 INFO [STDOUT] (main) Entered EJB log [Message!] 2011-03-23 17:14:57,430 INFO [org.apache.coyote.http11.Http11Protocol] (main) Starting Coyote HTTP/1.1 on http-127.0.0.1-8080 2011-03-23 17:14:57,446 INFO [org.apache.coyote.ajp.AjpProtocol] (main) Starting Coyote AJP/1.3 on ajp-127.0.0.1-8009 2011-03-23 17:14:57,446 INFO [org.jboss.bootstrap.microcontainer.ServerImpl] (main) JBoss (Microcontainer) [5.1.0.GA (build: SVNTag=JBoss_5_1_0_GA date=200905221634)] Started in 23s:516ms
No line is added to c:\test\mylog.log, the log file isn't touched at all. The log message is instead delivered to standard output (some basic configuration for SLF4J when specific definition is not found).
I also noted that it doesn't even find the multiple SLF4J bindings in the classpath.
I've attached the source code, it is a simple project that helped me reproduce the problem of the main project, and will simplify solving this problem. Or at least I hope so ...
Need some help, any help, any tips ... anything ...
Thanks in advance.
-
test.zip 15.9 KB