9:20 a.m.
JBoss Remoting logs at ERROR and WARN in many places
----------------------------------------------------
Key: JBREM-826
URL: http://jira.jboss.com/jira/browse/JBREM-826
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public (Everyone can see)
Reporter: Tim Fox
Fix For: 2.4.0.Beta1 (Pinto)
In many places JBoss Remoting logs at ERROR or WARN which seem inappropriate.
JBR is a toolkit and should not log errors it does not handle. If every toolkit being used
in the chain logged the same error then you end up with a complete mess in the logs every
time an exeception occurs.
There is a general principle of you shouldn't log unless you handle the error. If you
just pass it up, don't log. This principle is adhered to in JBoss AS for example, and
IMHO should be used throughout all JBoss projectsd
Failover in JBoss Messaging is a good example.
In JBM we detect failure of the remoting connection via the connection listener, and
transparently reconnect on a different node. In this case, from the users POV *no error*
has occurred - the process should be completely seamless.
However JBoss Remoting spews a load of exceptions to the logs at ERROR and WARN, for
example:
@main 08:01:30,648 INFO [ServerManagement] Waiting for server to die
@main 08:01:30,953 INFO [ServerManagement] server 1 killed and dead
@Timer-3 08:01:31,253 ERROR [SocketClientInvoker] Got marshalling exception, exiting
java.net.SocketException: end of file
at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:577)
at
org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:413)
at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at
org.jboss.remoting.ConnectionValidator.doCheckConnection(ConnectionValidator.java:133)
at org.jboss.remoting.ConnectionValidator.run(ConnectionValidator.java:308)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
@Thread-9 08:01:31,277 WARN [ClientClusteredConnectionFactoryDelegate]
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem
establishing socket connection for InvokerLocator
[bisocket://localhost:2117/?clientLeasePeriod=10000&clientMaxPoolSize=200&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat]
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem
establishing socket connection for InvokerLocator
[bisocket://localhost:2117/?clientLeasePeriod=10000&clientMaxPoolSize=200&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat]
at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:532)
at
org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:413)
at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.Client.invoke(Client.java:1634)
at org.jboss.remoting.Client.invoke(Client.java:548)
at
org.jboss.jms.client.delegate.ClientClusteredConnectionFactoryDelegate.removeCallback(ClientClusteredConnectionFactoryDelegate.java:152)
at
org.jboss.jms.client.delegate.ClientClusteredConnectionFactoryDelegate.closeCallback(ClientClusteredConnectionFactoryDelegate.java:168)
at
org.jboss.jms.client.delegate.ClientClusteredConnectionFactoryDelegate.establishCallback(ClientClusteredConnectionFactoryDelegate.java:93)
at
org.jboss.jms.client.remoting.ConnectionFactoryCallbackHandler$CallbackConnectionListener.handleConnectionException(ConnectionFactoryCallbackHandler.java:105)
at org.jboss.remoting.ConnectionValidator$1.run(ConnectionValidator.java:452)
Caused by: java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at
org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187)
at
org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:420)
at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:815)
at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
... 9 more
@Thread-9 08:01:31,299 WARN [Client] unable to remove remote callback handler: Can not
get connection to server. Problem establishing socket connection for InvokerLocator
[bisocket://localhost:2117/?clientLeasePeriod=10000&clientMaxPoolSize=200&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat]
SERVER 0 STDOUT: @Timer-4 08:01:31,301 ERROR [SocketClientInvoker] Got marshalling
exception, exiting
SERVER 0 STDOUT: java.net.SocketException: end of file
SERVER 0 STDOUT: at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:577)
SERVER 0 STDOUT: at
org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:413)
SERVER 0 STDOUT: at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
@Thread-9 08:01:31,320 WARN [LeasePinger] LeasePinger[SocketClientInvoker[c0f1ec,
bisocket://localhost:2117](3j001-bj8ucn-f8e4sbxc-1-f8e4sby7-3)] failed sending disconnect
for client lease for client with session ID 3j001-bj8ucn-f8e4sbxc-1-f8e4sbxd-2
SERVER 0 STDOUT: at
org.jboss.remoting.ConnectionValidator.doCheckConnection(ConnectionValidator.java:133)
SERVER 0 STDOUT: at
org.jboss.remoting.ConnectionValidator.run(ConnectionValidator.java:308)
SERVER 0 STDOUT: at java.util.TimerThread.mainLoop(Timer.java:512)
SERVER 0 STDOUT: at java.util.TimerThread.run(Timer.java:462)
@Thread-9 08:01:31,345 WARN [LeasePinger] LeasePinger[SocketClientInvoker[c0f1ec,
bisocket://localhost:2117](3j001-bj8ucn-f8e4sbxc-1-f8e4sby7-3)] failed to ping to server:
Can not get connection to server. Problem establishing socket connection for
InvokerLocator [bisocket://localhost:2117/?cli
This completely messes up the logs and the customer believes something has gone wrong,
phones support and they waste a lot of time trying to work out what the problem is, when
actually there is no problem and this is perfectly successful failover from one node to
another, but to the customer they have a flawed experience.
If anything is to be logged in these cases it should be at DEBUG level at the highest, so
it can be easily supressed in the standard log4j config.
In the mean-time if you could provide a log4j config which supresses these messages for
the specific classes so they don't appear even on ERROR level that would be much
appreciated.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.jboss.com/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira