Jboss Logging with SLF4J in EJB : breaks logging
Hi,
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
