[JBoss JIRA] Created: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
10:30 a.m.
New Socket Connection is being Created for Every Client Request to the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public (Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Priority: Critical
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
7:25 p.m.
New subject: [JBoss JIRA] Updated: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal updated JBREM-877:
----------------------------
Fix Version/s: 2.4.0.Beta1 (Pinto)
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Priority: Critical
Fix For: 2.4.0.Beta1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
7:25 p.m.
New subject: [JBoss JIRA] Commented: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=comments#action_12392505 ]
Ron Sigal commented on JBREM-877:
---------------------------------
Kumarselvan, what is your evidence for this behavior? Do you have some log file(s)?
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Priority: Critical
Fix For: 2.4.0.Beta1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
11:09 p.m.
New subject: [JBoss JIRA] Commented: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=comments#action_12392518 ]
Kumarselvan Somasundaram commented on JBREM-877:
------------------------------------------------
i am getting the following log:
2007-12-17 20:12:33,138 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper]
reset timeout: 60000
2007-12-17 20:12:33,143 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
WorkerThread#1[131.10.20.210:40824] closing socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40824,localport=3873].229885]
2007-12-17 20:12:33,143 DEBUG [org.jboss.remoting.transport.socket.ServerSocketWrapper]
wrote CLOSING
2007-12-17 20:12:33,143 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40824,localport=3873].229885] closing
2007-12-17 20:12:33,231 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper]
reset timeout: 60000
2007-12-17 20:12:33,236 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
WorkerThread#0[131.10.20.210:40825] closing socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40825,localport=3873].aea1a2]
2007-12-17 20:12:33,236 DEBUG [org.jboss.remoting.transport.socket.ServerSocketWrapper]
wrote CLOSING
2007-12-17 20:12:33,236 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40825,localport=3873].aea1a2] closing
2007-12-17 20:12:33,247 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper]
reset timeout: 60000
2007-12-17 20:12:33,252 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
WorkerThread#1[131.10.20.210:40826] closing socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40826,localport=3873].5cf1a4]
2007-12-17 20:12:33,252 DEBUG [org.jboss.remoting.transport.socket.ServerSocketWrapper]
wrote CLOSING
2007-12-17 20:12:33,252 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40826,localport=3873].5cf1a4] closing
2007-12-17 20:12:33,259 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper]
reset timeout: 60000
2007-12-17 20:12:33,265 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
WorkerThread#0[131.10.20.210:40827] closing socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40827,localport=3873].150a19a]
2007-12-17 20:12:33,265 DEBUG [org.jboss.remoting.transport.socket.ServerSocketWrapper]
wrote CLOSING
2007-12-17 20:12:33,265 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40827,localport=3873].150a19a]
closing
2007-12-17 20:12:33,331 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper]
reset timeout: 60000
2007-12-17 20:12:33,336 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
WorkerThread#1[131.10.20.210:40828] closing socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40828,localport=3873].1c3f810]
2007-12-17 20:12:33,336 DEBUG [org.jboss.remoting.transport.socket.ServerSocketWrapper]
wrote CLOSING
2007-12-17 20:12:33,336 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40828,localport=3873].1c3f810]
closing
2007-12-17 20:12:33,372 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper]
reset timeout: 60000
2007-12-17 20:12:33,376 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
WorkerThread#0[131.10.20.210:40829] closing socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.210,port=40829,localport=3873].1be1b4]
"se
This is keep on happening.....
also i have seen in the netstat -nac | grep 3873
in this i am able to see the client side port is changing and it is increasing for each
connections made
I am using default configuration of ejb3 remoting conf
<mbean code="org.jboss.remoting.transport.Connector"
name="jboss.remoting:type=Connector,name=DefaultEjb3Connector,handler=ejb3">
<depends>jboss.aop:service=AspectDeployer</depends>
<attribute
name="InvokerLocator">socket://${jboss.bind.address}:3873</attribute>
<attribute name="Configuration">
<handlers>
<handler
subsystem="AOP">org.jboss.aspects.remoting.AOPRemotingInvocationHandler</handler>
</handlers>
</attribute>
</mbean>
Is there is any other configration change i need to make it with the current release so
that the problem i am having will get resolved...
One thing i am not able to understand is y the connection getting closed for each call at
the server side, this closing needs to happen only after the timeout.
i Hope there is some exception which causes the connection to close forcely...
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Priority: Critical
Fix For: 2.4.0.Beta1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
4:37 p.m.
New subject: [JBoss JIRA] Assigned: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal reassigned JBREM-877:
-------------------------------
Assignee: Ron Sigal
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.Beta1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
4:37 p.m.
New subject: [JBoss JIRA] Commented: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=comments#action_12393193 ]
Ron Sigal commented on JBREM-877:
---------------------------------
Starting a forum thread:
http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4114821#....
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Priority: Critical
Fix For: 2.4.0.Beta1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
4:37 p.m.
New subject: [JBoss JIRA] Updated: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal updated JBREM-877:
----------------------------
JBoss Forum Reference:
http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4114821#...
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Priority: Critical
Fix For: 2.4.0.Beta1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
4:57 a.m.
New subject: [JBoss JIRA] Commented: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=comments#action_12393340 ]
Kumarselvan Somasundaram commented on JBREM-877:
------------------------------------------------
Hi Ron Sigal,
I have given the trace log i got after i have enabled the TRACE Loglevel for
remoting.....
Please help me out on this
2007-12-24 16:13:57,968 185859 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2508]:) SocketServerInvoker[131.10.20.40:3873] successfully
dispatched invocation, returning org.jboss.aop.joinpoint.InvocationResponse@d5a86c from
subsystem 'AOP' to client 3nak14-awcxm4-fakvt4xg-1-fakvt4xg-2
2007-12-24 16:13:57,968 185859 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) SocketServerInvoker[131.10.20.40:3873].invoke()
returned org.jboss.aop.joinpoint.InvocationResponse@d5a86c
2007-12-24 16:13:57,968 185859 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) creating response instance
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] accepted
Socket[addr=/131.10.20.40,port=2513,localport=3873]
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] trying to get a worker thread from threadpool for
processing
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] has an empty threadpool
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] creating new worker thread
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] created WorkerThread#1[131.10.20.40:2513]
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] starting WorkerThread#1[131.10.20.40:2513]
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:) passed
through ServerSocketRefresh.release()
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] is going to wait on serverSocket.accept()
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) wrote response to the output stream
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) preparing to process next invocation invocation
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) blocking to read version from input stream
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) read version -1 from input stream
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) EOFException received. This is likely due to client
finishing communication.
java.io.EOFException
at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:530)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
2007-12-24 16:13:58,000 185891 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) WorkerThread#0[131.10.20.40:2508] closing
socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2508,localport=3873].8f337b]
2007-12-24 16:13:58,000 185891 DEBUG
[org.jboss.remoting.transport.socket.ServerSocketWrapper]
(WorkerThread#0[131.10.20.40:2508]:) wrote CLOSING
2007-12-24 16:13:58,000 185891 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2508]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2508,localport=3873].8f337b] closing
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) WorkerThread#0[131.10.20.40:2508] removing itself
from clientpool and going to threadpool
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2508]:) WorkerThread#0[131.10.20.40:2508] begins to wait
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) beginning dorun()
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) creating the socket wrapper
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2513]:) constructing
org.jboss.remoting.transport.socket.ServerSocketWrapper instance for
Socket[addr=/131.10.20.40,port=2513,localport=3873], using timeout 60000
2007-12-24 16:13:58,000 185891 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2513]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2513,localport=3873].db06de] setting
timeout to 60000
2007-12-24 16:13:58,000 185891 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2513]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2513,localport=3873].db06de] getting
output stream from Socket[addr=/131.10.20.40,port=2513,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableMarshaller@19febb9
2007-12-24 16:13:58,000 185891 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#1[131.10.20.40:2513]:) Creating ObjectOutputStream
2007-12-24 16:13:58,015 185906 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2513]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2513,localport=3873].db06de] getting
input stream from Socket[addr=/131.10.20.40,port=2513,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableUnMarshaller@2cd301
2007-12-24 16:13:58,015 185906 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#1[131.10.20.40:2513]:) Creating ObjectInputStreamWithClassLoader
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2513]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2513,localport=3873].db06de] setting
timeout to 60000
2007-12-24 16:13:58,015 185906 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2513]:) reset timeout: 60000
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) processing first invocation without acknowledging
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) preparing to process next invocation invocation
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) blocking to read version from input stream
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) read version 22 from input stream
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) blocking to read invocation from unmarshaller
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) read InvocationRequest[d1223d, AOP,
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from unmarshaller
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) about to call
SocketServerInvoker[131.10.20.40:3873].invoke()
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2513]:) SocketServerInvoker[131.10.20.40:3873] received
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]
2007-12-24 16:13:58,015 185906 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2513]:) SocketServerInvoker[131.10.20.40:3873] dispatching
InvocationRequest[d1223d, AOP, [advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from client 3nak14-awcxm4-fakvt4xg-1-fakvt6lc-4 to
subsystem 'AOP'
2007-12-24 16:13:58,125 186016 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2513]:) SocketServerInvoker[131.10.20.40:3873] successfully
dispatched invocation, returning org.jboss.aop.joinpoint.InvocationResponse@158bc22 from
subsystem 'AOP' to client 3nak14-awcxm4-fakvt4xg-1-fakvt6lc-4
2007-12-24 16:13:58,125 186016 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) SocketServerInvoker[131.10.20.40:3873].invoke()
returned org.jboss.aop.joinpoint.InvocationResponse@158bc22
2007-12-24 16:13:58,125 186016 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) creating response instance
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) wrote response to the output stream
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) preparing to process next invocation invocation
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) blocking to read version from input stream
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) read version -1 from input stream
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) EOFException received. This is likely due to client
finishing communication.
java.io.EOFException
at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:530)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
2007-12-24 16:13:58,468 186359 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) WorkerThread#1[131.10.20.40:2513] closing
socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2513,localport=3873].db06de]
2007-12-24 16:13:58,468 186359 DEBUG
[org.jboss.remoting.transport.socket.ServerSocketWrapper]
(WorkerThread#1[131.10.20.40:2513]:) wrote CLOSING
2007-12-24 16:13:58,468 186359 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2513]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2513,localport=3873].db06de] closing
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) WorkerThread#1[131.10.20.40:2513] removing itself
from clientpool and going to threadpool
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2513]:) WorkerThread#1[131.10.20.40:2513] begins to wait
2007-12-24 16:13:58,468 186359 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] accepted
Socket[addr=/131.10.20.40,port=2514,localport=3873]
2007-12-24 16:13:58,468 186359 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] trying to get a worker thread from threadpool for
processing
2007-12-24 16:13:58,468 186359 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] got WorkerThread#0[131.10.20.40:2508] from
threadpool
2007-12-24 16:13:58,468 186359 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] reusing WorkerThread#0[131.10.20.40:2508]
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(AcceptorThread#0:3873:) WorkerThread#0[131.10.20.40:2514] has notified on mutex
2007-12-24 16:13:58,468 186359 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:) passed
through ServerSocketRefresh.release()
2007-12-24 16:13:58,468 186359 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] is going to wait on serverSocket.accept()
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) WorkerThread#0[131.10.20.40:2514] woke up after wait
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) beginning dorun()
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) creating the socket wrapper
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2514]:) constructing
org.jboss.remoting.transport.socket.ServerSocketWrapper instance for
Socket[addr=/131.10.20.40,port=2514,localport=3873], using timeout 60000
2007-12-24 16:13:58,468 186359 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2514]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2514,localport=3873].a3aaf5] setting
timeout to 60000
2007-12-24 16:13:58,468 186359 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2514]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2514,localport=3873].a3aaf5] getting
output stream from Socket[addr=/131.10.20.40,port=2514,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableMarshaller@17cd18d
2007-12-24 16:13:58,468 186359 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#0[131.10.20.40:2514]:) Creating ObjectOutputStream
2007-12-24 16:13:58,468 186359 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2514]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2514,localport=3873].a3aaf5] getting
input stream from Socket[addr=/131.10.20.40,port=2514,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableUnMarshaller@1a183d2
2007-12-24 16:13:58,468 186359 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#0[131.10.20.40:2514]:) Creating ObjectInputStreamWithClassLoader
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2514]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2514,localport=3873].a3aaf5] setting
timeout to 60000
2007-12-24 16:13:58,484 186375 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2514]:) reset timeout: 60000
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) processing first invocation without acknowledging
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) preparing to process next invocation invocation
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) blocking to read version from input stream
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) read version 22 from input stream
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) blocking to read invocation from unmarshaller
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) read InvocationRequest[12cc66f, AOP,
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from unmarshaller
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) about to call
SocketServerInvoker[131.10.20.40:3873].invoke()
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2514]:) SocketServerInvoker[131.10.20.40:3873] received
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]
2007-12-24 16:13:58,484 186375 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2514]:) SocketServerInvoker[131.10.20.40:3873] dispatching
InvocationRequest[12cc66f, AOP, [advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from client 3nak14-awcxm4-fakvt4xg-1-fakvt6wm-6 to
subsystem 'AOP'
2007-12-24 16:13:58,500 186391 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2514]:) SocketServerInvoker[131.10.20.40:3873] successfully
dispatched invocation, returning org.jboss.aop.joinpoint.InvocationResponse@25352b from
subsystem 'AOP' to client 3nak14-awcxm4-fakvt4xg-1-fakvt6wm-6
2007-12-24 16:13:58,500 186391 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) SocketServerInvoker[131.10.20.40:3873].invoke()
returned org.jboss.aop.joinpoint.InvocationResponse@25352b
2007-12-24 16:13:58,500 186391 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) creating response instance
2007-12-24 16:13:58,515 186406 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] accepted
Socket[addr=/131.10.20.40,port=2515,localport=3873]
2007-12-24 16:13:58,515 186406 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] trying to get a worker thread from threadpool for
processing
2007-12-24 16:13:58,515 186406 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] got WorkerThread#1[131.10.20.40:2513] from
threadpool
2007-12-24 16:13:58,515 186406 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] reusing WorkerThread#1[131.10.20.40:2513]
2007-12-24 16:13:58,515 186406 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(AcceptorThread#0:3873:) WorkerThread#1[131.10.20.40:2515] has notified on mutex
2007-12-24 16:13:58,515 186406 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:) passed
through ServerSocketRefresh.release()
2007-12-24 16:13:58,515 186406 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] is going to wait on serverSocket.accept()
2007-12-24 16:13:58,515 186406 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) WorkerThread#1[131.10.20.40:2515] woke up after wait
2007-12-24 16:13:58,515 186406 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) beginning dorun()
2007-12-24 16:13:58,515 186406 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) creating the socket wrapper
2007-12-24 16:13:58,515 186406 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2515]:) constructing
org.jboss.remoting.transport.socket.ServerSocketWrapper instance for
Socket[addr=/131.10.20.40,port=2515,localport=3873], using timeout 60000
2007-12-24 16:13:58,515 186406 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2515]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2515,localport=3873].51e62] setting
timeout to 60000
2007-12-24 16:13:58,531 186422 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2515]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2515,localport=3873].51e62] getting
output stream from Socket[addr=/131.10.20.40,port=2515,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableMarshaller@19febb9
2007-12-24 16:13:58,531 186422 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#1[131.10.20.40:2515]:) Creating ObjectOutputStream
2007-12-24 16:13:58,531 186422 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2515]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2515,localport=3873].51e62] getting
input stream from Socket[addr=/131.10.20.40,port=2515,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableUnMarshaller@2cd301
2007-12-24 16:13:58,531 186422 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#1[131.10.20.40:2515]:) Creating ObjectInputStreamWithClassLoader
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2515]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2515,localport=3873].51e62] setting
timeout to 60000
2007-12-24 16:13:58,531 186422 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2515]:) reset timeout: 60000
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) processing first invocation without acknowledging
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) preparing to process next invocation invocation
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) blocking to read version from input stream
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) read version 22 from input stream
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) blocking to read invocation from unmarshaller
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) read InvocationRequest[dddff, AOP,
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from unmarshaller
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) about to call
SocketServerInvoker[131.10.20.40:3873].invoke()
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2515]:) SocketServerInvoker[131.10.20.40:3873] received
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2515]:) SocketServerInvoker[131.10.20.40:3873] dispatching
InvocationRequest[dddff, AOP, [advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from client 3nak14-awcxm4-fakvt4xg-1-fakvt703-8 to
subsystem 'AOP'
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) wrote response to the output stream
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) preparing to process next invocation invocation
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) blocking to read version from input stream
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) read version -1 from input stream
2007-12-24 16:13:58,531 186422 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) EOFException received. This is likely due to client
finishing communication.
java.io.EOFException
at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:530)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
2007-12-24 16:13:58,531 186422 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) WorkerThread#0[131.10.20.40:2514] closing
socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2514,localport=3873].a3aaf5]
2007-12-24 16:13:58,531 186422 DEBUG
[org.jboss.remoting.transport.socket.ServerSocketWrapper]
(WorkerThread#0[131.10.20.40:2514]:) wrote CLOSING
2007-12-24 16:13:58,546 186437 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2514]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2514,localport=3873].a3aaf5] closing
2007-12-24 16:13:58,546 186437 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) WorkerThread#0[131.10.20.40:2514] removing itself
from clientpool and going to threadpool
2007-12-24 16:13:58,546 186437 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2514]:) WorkerThread#0[131.10.20.40:2514] begins to wait
2007-12-24 16:13:58,562 186453 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2515]:) SocketServerInvoker[131.10.20.40:3873] successfully
dispatched invocation, returning org.jboss.aop.joinpoint.InvocationResponse@7dcb35 from
subsystem 'AOP' to client 3nak14-awcxm4-fakvt4xg-1-fakvt703-8
2007-12-24 16:13:58,562 186453 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) SocketServerInvoker[131.10.20.40:3873].invoke()
returned org.jboss.aop.joinpoint.InvocationResponse@7dcb35
2007-12-24 16:13:58,562 186453 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) creating response instance
2007-12-24 16:13:58,578 186469 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] accepted
Socket[addr=/131.10.20.40,port=2516,localport=3873]
2007-12-24 16:13:58,578 186469 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] trying to get a worker thread from threadpool for
processing
2007-12-24 16:13:58,578 186469 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] got WorkerThread#0[131.10.20.40:2514] from
threadpool
2007-12-24 16:13:58,578 186469 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] reusing WorkerThread#0[131.10.20.40:2514]
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(AcceptorThread#0:3873:) WorkerThread#0[131.10.20.40:2516] has notified on mutex
2007-12-24 16:13:58,578 186469 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:) passed
through ServerSocketRefresh.release()
2007-12-24 16:13:58,578 186469 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] is going to wait on serverSocket.accept()
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) WorkerThread#0[131.10.20.40:2516] woke up after wait
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) beginning dorun()
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) creating the socket wrapper
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2516]:) constructing
org.jboss.remoting.transport.socket.ServerSocketWrapper instance for
Socket[addr=/131.10.20.40,port=2516,localport=3873], using timeout 60000
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2516]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2516,localport=3873].f4aa7a] setting
timeout to 60000
2007-12-24 16:13:58,578 186469 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2516]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2516,localport=3873].f4aa7a] getting
output stream from Socket[addr=/131.10.20.40,port=2516,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableMarshaller@17cd18d
2007-12-24 16:13:58,578 186469 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#0[131.10.20.40:2516]:) Creating ObjectOutputStream
2007-12-24 16:13:58,578 186469 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2516]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2516,localport=3873].f4aa7a] getting
input stream from Socket[addr=/131.10.20.40,port=2516,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableUnMarshaller@1a183d2
2007-12-24 16:13:58,578 186469 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#0[131.10.20.40:2516]:) Creating ObjectInputStreamWithClassLoader
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2516]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2516,localport=3873].f4aa7a] setting
timeout to 60000
2007-12-24 16:13:58,578 186469 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2516]:) reset timeout: 60000
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) processing first invocation without acknowledging
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) preparing to process next invocation invocation
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) blocking to read version from input stream
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) read version 22 from input stream
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) blocking to read invocation from unmarshaller
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) read InvocationRequest[e44dd3, AOP,
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from unmarshaller
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) about to call
SocketServerInvoker[131.10.20.40:3873].invoke()
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2516]:) SocketServerInvoker[131.10.20.40:3873] received
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]
2007-12-24 16:13:58,578 186469 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2516]:) SocketServerInvoker[131.10.20.40:3873] dispatching
InvocationRequest[e44dd3, AOP, [advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=GatekeeperSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from client 3nak14-awcxm4-fakvt4xg-1-fakvt71e-a to
subsystem 'AOP'
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) wrote response to the output stream
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) preparing to process next invocation invocation
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) blocking to read version from input stream
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) read version -1 from input stream
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) EOFException received. This is likely due to client
finishing communication.
java.io.EOFException
at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:530)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
2007-12-24 16:13:58,593 186484 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) WorkerThread#1[131.10.20.40:2515] closing
socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2515,localport=3873].51e62]
2007-12-24 16:13:58,593 186484 DEBUG
[org.jboss.remoting.transport.socket.ServerSocketWrapper]
(WorkerThread#1[131.10.20.40:2515]:) wrote CLOSING
2007-12-24 16:13:58,593 186484 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2515]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2515,localport=3873].51e62] closing
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) WorkerThread#1[131.10.20.40:2515] removing itself
from clientpool and going to threadpool
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2515]:) WorkerThread#1[131.10.20.40:2515] begins to wait
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2516]:) SocketServerInvoker[131.10.20.40:3873] successfully
dispatched invocation, returning org.jboss.aop.joinpoint.InvocationResponse@15c0d7 from
subsystem 'AOP' to client 3nak14-awcxm4-fakvt4xg-1-fakvt71e-a
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) SocketServerInvoker[131.10.20.40:3873].invoke()
returned org.jboss.aop.joinpoint.InvocationResponse@15c0d7
2007-12-24 16:13:58,593 186484 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) creating response instance
2007-12-24 16:13:58,718 186609 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) wrote response to the output stream
2007-12-24 16:13:58,718 186609 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) preparing to process next invocation invocation
2007-12-24 16:13:58,718 186609 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) blocking to read version from input stream
2007-12-24 16:13:58,718 186609 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) read version -1 from input stream
2007-12-24 16:13:58,718 186609 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) EOFException received. This is likely due to client
finishing communication.
java.io.EOFException
at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:530)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
2007-12-24 16:13:58,718 186609 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) WorkerThread#0[131.10.20.40:2516] closing
socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2516,localport=3873].f4aa7a]
2007-12-24 16:13:58,734 186625 DEBUG
[org.jboss.remoting.transport.socket.ServerSocketWrapper]
(WorkerThread#0[131.10.20.40:2516]:) wrote CLOSING
2007-12-24 16:13:58,734 186625 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2516]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2516,localport=3873].f4aa7a] closing
2007-12-24 16:13:58,734 186625 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) WorkerThread#0[131.10.20.40:2516] removing itself
from clientpool and going to threadpool
2007-12-24 16:13:58,734 186625 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2516]:) WorkerThread#0[131.10.20.40:2516] begins to wait
2007-12-24 16:13:59,296 187187 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] accepted
Socket[addr=/131.10.20.40,port=2517,localport=3873]
2007-12-24 16:13:59,296 187187 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] trying to get a worker thread from threadpool for
processing
2007-12-24 16:13:59,296 187187 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] got WorkerThread#1[131.10.20.40:2515] from
threadpool
2007-12-24 16:13:59,296 187187 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] reusing WorkerThread#1[131.10.20.40:2515]
2007-12-24 16:13:59,296 187187 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(AcceptorThread#0:3873:) WorkerThread#1[131.10.20.40:2517] has notified on mutex
2007-12-24 16:13:59,296 187187 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:) passed
through ServerSocketRefresh.release()
2007-12-24 16:13:59,296 187187 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] is going to wait on serverSocket.accept()
2007-12-24 16:13:59,296 187187 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) WorkerThread#1[131.10.20.40:2517] woke up after wait
2007-12-24 16:13:59,296 187187 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) beginning dorun()
2007-12-24 16:13:59,296 187187 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) creating the socket wrapper
2007-12-24 16:13:59,296 187187 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2517]:) constructing
org.jboss.remoting.transport.socket.ServerSocketWrapper instance for
Socket[addr=/131.10.20.40,port=2517,localport=3873], using timeout 60000
2007-12-24 16:13:59,296 187187 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2517]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2517,localport=3873].1dd1c39] setting
timeout to 60000
2007-12-24 16:13:59,296 187187 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2517]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2517,localport=3873].1dd1c39] getting
output stream from Socket[addr=/131.10.20.40,port=2517,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableMarshaller@19febb9
2007-12-24 16:13:59,296 187187 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#1[131.10.20.40:2517]:) Creating ObjectOutputStream
2007-12-24 16:13:59,312 187203 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2517]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2517,localport=3873].1dd1c39] getting
input stream from Socket[addr=/131.10.20.40,port=2517,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableUnMarshaller@2cd301
2007-12-24 16:13:59,312 187203 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#1[131.10.20.40:2517]:) Creating ObjectInputStreamWithClassLoader
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2517]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2517,localport=3873].1dd1c39] setting
timeout to 60000
2007-12-24 16:13:59,312 187203 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2517]:) reset timeout: 60000
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) processing first invocation without acknowledging
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) preparing to process next invocation invocation
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) blocking to read version from input stream
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) read version 22 from input stream
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) blocking to read invocation from unmarshaller
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) read InvocationRequest[1681460, AOP,
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from unmarshaller
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) about to call
SocketServerInvoker[131.10.20.40:3873].invoke()
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2517]:) SocketServerInvoker[131.10.20.40:3873] received
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]
2007-12-24 16:13:59,312 187203 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2517]:) SocketServerInvoker[131.10.20.40:3873] dispatching
InvocationRequest[1681460, AOP, [advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from client 3nak14-awcxm4-fakvt4xg-1-fakvt7ls-c to
subsystem 'AOP'
2007-12-24 16:13:59,703 187594 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2517]:) SocketServerInvoker[131.10.20.40:3873] successfully
dispatched invocation, returning org.jboss.aop.joinpoint.InvocationResponse@928095 from
subsystem 'AOP' to client 3nak14-awcxm4-fakvt4xg-1-fakvt7ls-c
2007-12-24 16:13:59,703 187594 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) SocketServerInvoker[131.10.20.40:3873].invoke()
returned org.jboss.aop.joinpoint.InvocationResponse@928095
2007-12-24 16:13:59,703 187594 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) creating response instance
2007-12-24 16:13:59,781 187672 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) wrote response to the output stream
2007-12-24 16:13:59,781 187672 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) preparing to process next invocation invocation
2007-12-24 16:13:59,781 187672 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) blocking to read version from input stream
2007-12-24 16:13:59,843 187734 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) read version -1 from input stream
2007-12-24 16:13:59,843 187734 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) EOFException received. This is likely due to client
finishing communication.
java.io.EOFException
at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:530)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
2007-12-24 16:13:59,843 187734 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) WorkerThread#1[131.10.20.40:2517] closing
socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2517,localport=3873].1dd1c39]
2007-12-24 16:13:59,843 187734 DEBUG
[org.jboss.remoting.transport.socket.ServerSocketWrapper]
(WorkerThread#1[131.10.20.40:2517]:) wrote CLOSING
2007-12-24 16:13:59,843 187734 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2517]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2517,localport=3873].1dd1c39] closing
2007-12-24 16:13:59,843 187734 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) WorkerThread#1[131.10.20.40:2517] removing itself
from clientpool and going to threadpool
2007-12-24 16:13:59,843 187734 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2517]:) WorkerThread#1[131.10.20.40:2517] begins to wait
2007-12-24 16:13:59,859 187750 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] accepted
Socket[addr=/131.10.20.40,port=2518,localport=3873]
2007-12-24 16:13:59,859 187750 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] trying to get a worker thread from threadpool for
processing
2007-12-24 16:13:59,859 187750 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] got WorkerThread#0[131.10.20.40:2516] from
threadpool
2007-12-24 16:13:59,859 187750 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] reusing WorkerThread#0[131.10.20.40:2516]
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(AcceptorThread#0:3873:) WorkerThread#0[131.10.20.40:2518] has notified on mutex
2007-12-24 16:13:59,859 187750 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:) passed
through ServerSocketRefresh.release()
2007-12-24 16:13:59,859 187750 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] is going to wait on serverSocket.accept()
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) WorkerThread#0[131.10.20.40:2518] woke up after wait
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) beginning dorun()
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) creating the socket wrapper
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2518]:) constructing
org.jboss.remoting.transport.socket.ServerSocketWrapper instance for
Socket[addr=/131.10.20.40,port=2518,localport=3873], using timeout 60000
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2518]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2518,localport=3873].117ffc5] setting
timeout to 60000
2007-12-24 16:13:59,859 187750 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2518]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2518,localport=3873].117ffc5] getting
output stream from Socket[addr=/131.10.20.40,port=2518,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableMarshaller@17cd18d
2007-12-24 16:13:59,859 187750 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#0[131.10.20.40:2518]:) Creating ObjectOutputStream
2007-12-24 16:13:59,859 187750 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2518]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2518,localport=3873].117ffc5] getting
input stream from Socket[addr=/131.10.20.40,port=2518,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableUnMarshaller@1a183d2
2007-12-24 16:13:59,859 187750 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#0[131.10.20.40:2518]:) Creating ObjectInputStreamWithClassLoader
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2518]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2518,localport=3873].117ffc5] setting
timeout to 60000
2007-12-24 16:13:59,859 187750 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#0[131.10.20.40:2518]:) reset timeout: 60000
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) processing first invocation without acknowledging
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) preparing to process next invocation invocation
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) blocking to read version from input stream
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) read version 22 from input stream
2007-12-24 16:13:59,859 187750 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) blocking to read invocation from unmarshaller
2007-12-24 16:13:59,875 187766 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) read InvocationRequest[99146a, AOP,
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from unmarshaller
2007-12-24 16:13:59,875 187766 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) about to call
SocketServerInvoker[131.10.20.40:3873].invoke()
2007-12-24 16:13:59,875 187766 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2518]:) SocketServerInvoker[131.10.20.40:3873] received
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]
2007-12-24 16:13:59,875 187766 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2518]:) SocketServerInvoker[131.10.20.40:3873] dispatching
InvocationRequest[99146a, AOP, [advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from client 3nak14-awcxm4-fakvt4xg-1-fakvt81f-e to
subsystem 'AOP'
2007-12-24 16:13:59,875 187766 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#0[131.10.20.40:2518]:) SocketServerInvoker[131.10.20.40:3873] successfully
dispatched invocation, returning org.jboss.aop.joinpoint.InvocationResponse@1e9c46d from
subsystem 'AOP' to client 3nak14-awcxm4-fakvt4xg-1-fakvt81f-e
2007-12-24 16:13:59,875 187766 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) SocketServerInvoker[131.10.20.40:3873].invoke()
returned org.jboss.aop.joinpoint.InvocationResponse@1e9c46d
2007-12-24 16:13:59,875 187766 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) creating response instance
2007-12-24 16:13:59,890 187781 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] accepted
Socket[addr=/131.10.20.40,port=2519,localport=3873]
2007-12-24 16:13:59,890 187781 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] trying to get a worker thread from threadpool for
processing
2007-12-24 16:13:59,890 187781 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] got WorkerThread#1[131.10.20.40:2517] from
threadpool
2007-12-24 16:13:59,890 187781 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] reusing WorkerThread#1[131.10.20.40:2517]
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(AcceptorThread#0:3873:) WorkerThread#1[131.10.20.40:2519] has notified on mutex
2007-12-24 16:13:59,890 187781 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:) passed
through ServerSocketRefresh.release()
2007-12-24 16:13:59,890 187781 TRACE
[org.jboss.remoting.transport.socket.SocketServerInvoker] (AcceptorThread#0:3873:)
SocketServerInvoker[131.10.20.40:3873] is going to wait on serverSocket.accept()
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) WorkerThread#1[131.10.20.40:2519] woke up after wait
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) beginning dorun()
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) creating the socket wrapper
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2519]:) constructing
org.jboss.remoting.transport.socket.ServerSocketWrapper instance for
Socket[addr=/131.10.20.40,port=2519,localport=3873], using timeout 60000
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2519]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2519,localport=3873].1441dc0] setting
timeout to 60000
2007-12-24 16:13:59,890 187781 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2519]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2519,localport=3873].1441dc0] getting
output stream from Socket[addr=/131.10.20.40,port=2519,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableMarshaller@19febb9
2007-12-24 16:13:59,890 187781 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#1[131.10.20.40:2519]:) Creating ObjectOutputStream
2007-12-24 16:13:59,890 187781 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2519]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2519,localport=3873].1441dc0] getting
input stream from Socket[addr=/131.10.20.40,port=2519,localport=3873],
org.jboss.remoting.marshal.serializable.SerializableUnMarshaller@2cd301
2007-12-24 16:13:59,890 187781 TRACE
[org.jboss.remoting.serialization.impl.java.JavaSerializationManager]
(WorkerThread#1[131.10.20.40:2519]:) Creating ObjectInputStreamWithClassLoader
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) wrote response to the output stream
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) preparing to process next invocation invocation
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) blocking to read version from input stream
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) read version -1 from input stream
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) EOFException received. This is likely due to client
finishing communication.
java.io.EOFException
at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:530)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
2007-12-24 16:13:59,890 187781 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) WorkerThread#0[131.10.20.40:2518] closing
socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2518,localport=3873].117ffc5]
2007-12-24 16:13:59,890 187781 DEBUG
[org.jboss.remoting.transport.socket.ServerSocketWrapper]
(WorkerThread#0[131.10.20.40:2518]:) wrote CLOSING
2007-12-24 16:13:59,890 187781 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#0[131.10.20.40:2518]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2518,localport=3873].117ffc5] closing
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) WorkerThread#0[131.10.20.40:2518] removing itself
from clientpool and going to threadpool
2007-12-24 16:13:59,890 187781 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#0[131.10.20.40:2518]:) WorkerThread#0[131.10.20.40:2518] begins to wait
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2519]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2519,localport=3873].1441dc0] setting
timeout to 60000
2007-12-24 16:13:59,906 187797 DEBUG
[org.jboss.remoting.transport.socket.ClientSocketWrapper]
(WorkerThread#1[131.10.20.40:2519]:) reset timeout: 60000
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) processing first invocation without acknowledging
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) preparing to process next invocation invocation
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) blocking to read version from input stream
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) read version 22 from input stream
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) blocking to read invocation from unmarshaller
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) read InvocationRequest[fd5609, AOP,
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from unmarshaller
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) about to call
SocketServerInvoker[131.10.20.40:3873].invoke()
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2519]:) SocketServerInvoker[131.10.20.40:3873] received
[advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]
2007-12-24 16:13:59,906 187797 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2519]:) SocketServerInvoker[131.10.20.40:3873] dispatching
InvocationRequest[fd5609, AOP, [advisedMethod=null, unadvisedMethod=null,
metadata=[metaData={IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3,VMID=7fd3c9b85af1f0e9:-6d9356ce:1170bbdc8cf:-7fff]},
REMOTING={INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://131.10.20.40:3873/]],
SUBSYSTEM=[type=AS_ISvalue=AOP]},
DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=voip.ear,jar=voip-ejb.jar,name=ServicesSFBean,service=EJB3]}}],
targetObject=null, arguments=null]] from client 3nak14-awcxm4-fakvt4xg-1-fakvt82a-g to
subsystem 'AOP'
2007-12-24 16:13:59,921 187812 TRACE [org.jboss.remoting.ServerInvoker]
(WorkerThread#1[131.10.20.40:2519]:) SocketServerInvoker[131.10.20.40:3873] successfully
dispatched invocation, returning org.jboss.aop.joinpoint.InvocationResponse@986c47 from
subsystem 'AOP' to client 3nak14-awcxm4-fakvt4xg-1-fakvt82a-g
2007-12-24 16:13:59,921 187812 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) SocketServerInvoker[131.10.20.40:3873].invoke()
returned org.jboss.aop.joinpoint.InvocationResponse@986c47
2007-12-24 16:13:59,921 187812 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) creating response instance
2007-12-24 16:13:59,953 187844 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) wrote response to the output stream
2007-12-24 16:13:59,953 187844 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) preparing to process next invocation invocation
2007-12-24 16:13:59,953 187844 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) blocking to read version from input stream
2007-12-24 16:13:59,953 187844 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) read version -1 from input stream
2007-12-24 16:13:59,953 187844 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) EOFException received. This is likely due to client
finishing communication.
java.io.EOFException
at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:530)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
2007-12-24 16:13:59,953 187844 DEBUG [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) WorkerThread#1[131.10.20.40:2519] closing
socketWrapper:
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2519,localport=3873].1441dc0]
2007-12-24 16:13:59,953 187844 DEBUG
[org.jboss.remoting.transport.socket.ServerSocketWrapper]
(WorkerThread#1[131.10.20.40:2519]:) wrote CLOSING
2007-12-24 16:13:59,953 187844 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper]
(WorkerThread#1[131.10.20.40:2519]:)
ServerSocketWrapper[Socket[addr=/131.10.20.40,port=2519,localport=3873].1441dc0] closing
2007-12-24 16:13:59,953 187844 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) WorkerThread#1[131.10.20.40:2519] removing itself
from clientpool and going to threadpool
2007-12-24 16:13:59,953 187844 TRACE [org.jboss.remoting.transport.socket.ServerThread]
(WorkerThread#1[131.10.20.40:2519]:) WorkerThread#1[131.10.20.40:2519] begins to wait
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.Beta1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
10:50 p.m.
New subject: [JBoss JIRA] Updated: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal updated JBREM-877:
----------------------------
Fix Version/s: 2.4.0.CR1 (Pinto)
(was: 2.4.0.Beta1 (Pinto))
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.CR1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
1:19 a.m.
New subject: [JBoss JIRA] Commented: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=comments#action_12400394 ]
Ron Sigal commented on JBREM-877:
---------------------------------
I've added a new feature to org.jboss.remoting.Client which allows the destruction of
a client invoker to be delayed by some number of microseconds. The idea is to pick a
delay long enough that the client invoker will still be around to be used by the next
invocation on the same server.
The delay is turned off by default, but it can be turned on by setting the parameter
client.INVOKER_DESTRUCTION_DELAY (actual value "invokerDestructionDelay" to a
positive integer. The value can be set either by
* adding "invokerDestructionDelay=xxx" to the InvokerLocator, or
* adding the value with key "invokerDestructionDelay" to the configuration map
passed to the Client constructor.
For EJB3 clients, the value should be set in the Connection MBean in the file
<JBOSS_HOME>/server/<config>/deploy/ejb3.deployer/META-INF/jboss-service.xml.
Unit tests: org.jboss.test.remoting.invoker.ClientInvokerDelayedDestructionTestCase
Also committed org.jboss.test.remoting.invoker.InvokerDestructionTest, which illustrates
the cost of constantly recreating the client invoker. Some results can be found in the
related forum thread.
Waiting for results in hudson.
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.CR1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
1:21 a.m.
New subject: [JBoss JIRA] Updated: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal updated JBREM-877:
----------------------------
Affects: [Documentation (Ref Guide, User Guide, etc.)]
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.CR1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
9:13 p.m.
New subject: [JBoss JIRA] Closed: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal closed JBREM-877.
---------------------------
Resolution: Done
Tests pass in hudson.
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.CR1 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
3:47 a.m.
New subject: [JBoss JIRA] Reopened: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal reopened JBREM-877:
-----------------------------
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.Beta2 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
3:48 a.m.
New subject: [JBoss JIRA] Closed: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal closed JBREM-877.
---------------------------
Resolution: Done
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.Beta2 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
3:48 a.m.
New subject: [JBoss JIRA] Updated: (JBREM-877) New Socket Connection is being Created for Every Client Request to the Server
[ http://jira.jboss.com/jira/browse/JBREM-877?page=all ]
Ron Sigal updated JBREM-877:
----------------------------
Fix Version/s: 2.4.0.Beta2 (Pinto)
(was: 2.4.0.CR1 (Pinto))
New Socket Connection is being Created for Every Client Request to
the Server
-----------------------------------------------------------------------------
Key: JBREM-877
URL: http://jira.jboss.com/jira/browse/JBREM-877
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: transport
Affects Versions: 2.2.2.SP2
Environment: Linux os , Pentium duo Processor with 3.6 Ghz clock Speed, 4GB Ram
in this Postgresql Database also Running
Reporter: Kumarselvan Somasundaram
Assigned To: Ron Sigal
Priority: Critical
Fix For: 2.4.0.Beta2 (Pinto)
whenever EJB3 client requests the Server new socket is being created. at the client side
the socket connection pool is not being used. Hope there is some issue with the socket
connection after getting response from the server,becoz of which the server side the
connection is being closed. this increases the CPU utilization,
The same code is running fine in jboss 4.0.4 with jboss remoting 1.4.0
new remoting 2.2.2 SP4 only handling 1/4 of the load with high CPU utilization.
--
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
6161
days inactive
6235
days old
14 comments
2 participants
participants (2)
-
Kumarselvan Somasundaram (JIRA) -
Ron Sigal (JIRA)