SLSBs pooling not working as expected

glassfishrobot commented 17 years ago

Hi.

I tried a simple JAX-wS web service (a SLSB behind the scenes) that simulates a long time executing method:

@WebMethod public String espera5Minutos() {

try

{ TimeUnit.SECONDS.sleep(5 * 60); }

catch(Exception e){} return (new Date()).toString(); }

I deployed it to GF and then used the web service testing capabilities of JAX-WS (entering the URL of the web service on firefox with "?Tester" in the end). I openend three firefox tabs to simulate three "concurrent" requests to the service. I think GF should create three SLSB's and server the three requests in parallel, but it executes them serially, i.e., the first invocation returns after 5 minutes, the second after 10 and the third after 15.

Sometimes it executes the first two in parallel and the third serially.

The pooling settings were not modified.

Regards.

Environment

Operating System: Linux Platform: Linux

Affected Versions

[9.0pe]

glassfishrobot commented 6 years ago

Issue Imported From: https://github.com/javaee/glassfish/issues/2870
Original Issue Raised By:@glassfishrobot
Original Issue Assigned To: @yaminikb
Original Issue Closed By:@glassfishrobot

glassfishrobot commented 17 years ago

@glassfishrobot Commented mk111283 said: I tested using one of our devtests and it works fine.

The EJB Container is creating different instances to service the request. I will investigate this further but meanwhile Can you add a println to your method as follows and post the server.log?

@WebMethod public String espera5Minutos() { System.out.println(Thread.currentThread() + " ejb instance: " + this

" going to sleep..."); try

{ TimeUnit.SECONDS.sleep(5 * 60); }

catch(Exception e){} return (new Date()).toString(); }

glassfishrobot commented 17 years ago

@glassfishrobot Commented andresgr said: Created an attachment (id=884) GF server.log

glassfishrobot commented 17 years ago

@glassfishrobot Commented andresgr said: Hi.

The server.log is full of strange lines i don't understand O ("deferred registration RETRY").

The server.log: See attachment "GF server.log"

Some adittional data:

Machine executing GF: 1 GB RAM, 60GB of free disk space, AMD Athlon at 1,8 MHz, also executing tomcat and mysql.
jdk: jdk1.5.0_06
GF installation file: sjsas_pe-9_0_01-p01-linux.bin

glassfishrobot commented 17 years ago

@glassfishrobot Commented mk111283 said: I looked into the server.log but unfortunately, there is only line containing "sleeping for..."

Andresgr, looks like you created this log after hitting with one request. Could you please reproduce your original problem by trying it with concurrent requests?

glassfishrobot commented 17 years ago

@glassfishrobot Commented mk111283 said: I have tried many different domain.xml settings with concurrent requests from three browser (clients) and couldn't reproduce this. I have also verified that in any case the EJB Container does create multiple bean instances to service the concurrent requests. I am transfering this bug to the monitoring team to find out the root cause of the following message in the server.log: "deferred registration RETRY failed after 3204 milliseconds for "com.sun.appserv:standalone-ejb-module=AsynchWS1,name=espera5Minutos,type=bean-method,category=monitor,ejb=WSPrueba,server=server" (DEFERRING AGAIN)"

glassfishrobot commented 17 years ago

@glassfishrobot Commented andresgr said: Yeah, sorry for the mistake. Now i disabled monitoring and executed three concurrent requests again. The server.log extract should be more clear this time. I'm pasting it directly here:

<>

[#|2007-04-24T10:06:12.687+0200|INFO|sun-appserver-pe9.0|javax.enterprise.system.tools.deployment|_ThreadID=11;_ThreadName=httpWorkerThread-8080-1;EJB;WSPrueba;http://semlocal.mycompany.loc:8080/WSPruebaService/WSPrueba;|DPL5306:EJB Web Service Endpoint [WSPrueba] listening at address http://semlocal.mycompany.loc:8080/WSPruebaService/WSPrueba|#]

[#|2007-04-24T10:06:13.048+0200|INFO|sun-appserver-pe9.0|javax.enterprise.system.tools.deployment|_ThreadID=11;_ThreadName=httpWorkerThread-8080-1;EJB;WSPrueba;http://semlocal.mycompany.loc:8080/WSPruebaService/WSPrueba;|DPL5306:EJB Web Service Endpoint [WSPrueba] listening at address http://semlocal.mycompany.loc:8080/WSPruebaService/WSPrueba|#]

[#|2007-04-24T10:06:17.174+0200|INFO|sun-appserver-pe9.0|javax.enterprise.system.tools.deployment|_ThreadID=11;_ThreadName=httpWorkerThread-8080-1;EJB;WSPrueba;http://semlocal.mycompany.loc:8080/WSPruebaService/WSPrueba;|DPL5306:EJB Web Service Endpoint [WSPrueba] listening at address http://semlocal.mycompany.loc:8080/WSPruebaService/WSPrueba|#]

[#|2007-04-24T10:06:18.655+0200|INFO|sun-appserver-pe9.0|javax.enterprise.system.tools.deployment|_ThreadID=14;_ThreadName=httpWorkerThread-8080-3;EJB;WSPrueba;http://semlocal.mycompany.loc:8080/WSPruebaService/WSPrueba;|DPL5306:EJB Web Service Endpoint [WSPrueba] listening at address http://semlocal.mycompany.loc:8080/WSPruebaService/WSPrueba|#]

Regards.

glassfishrobot commented 17 years ago

@glassfishrobot Commented andresgr said: I reassigned (can i do that?) the issue to the original member, because of the additional provided data (and because i think this is not an admin monitoring issue).

Regards.

glassfishrobot commented 17 years ago

@glassfishrobot Commented andresgr said: forgot to change issue to ejb-container again...

glassfishrobot commented 17 years ago

@glassfishrobot Commented mk111283 said: This is still not an EJB Container issue. The SFSB instances are pooled and the pool is NOT limited by max-pool-size. The EJB Container itself doesn't manage threads. The requests arrive into the EJB Container through WEB or IIOP(Corba) path. If there is a hang, it could be well before the request arrive into the EJB container.

Having said this, I don't want to bounce this bug around.

Can you atleast provide the thread dump when you think that the appserver is hanging? You can do that by doing jstack -m .

To get the thread dump, (I am assuming that you are using a solaris machine) 1. jps -mlvV (and note down the process id of appserver ) 2. $JAVA_HOME/bin/jstack -m (redirect the output into a file)

Please post your test app, domain.xml, server.log and the jstack output

glassfishrobot commented 17 years ago

@glassfishrobot Commented mk111283 said: On solaris this will help you to get the stack trace:

Add the following to the domain.xml under along with other

-XX:+UnlockDiagnosticVMOptions -XX:+LogVMOutput -XX:LogFile=/tmp/jvm.log Then restart the server using asadmin start-domain Once you have the hang, send kill -3 . The output will go to the file specified in the -XX:LogFile option. Note:- Watchout for the messages on the terminal where you started the appserver. You may see "Warning: Forcing option -XX:LogFile=/tmp//hs_pid.log In which case post the file in the /tmp directory

glassfishrobot commented 17 years ago

@glassfishrobot Commented andresgr said: Created an attachment (id=893) domain.xml

glassfishrobot commented 17 years ago

@glassfishrobot Commented andresgr said: Created an attachment (id=894) Netbeans project

glassfishrobot commented 17 years ago

@glassfishrobot Commented andresgr said: First of all: i'm running GF on Linux (Fedora Core 6), not Solaris.

I didn't say GF is hanging, what is happening is that the third request waits until the first ends, and from the server.log output it seems that GF is only creating 2 SLSBs (note: SLSBs, not SFSBs).

Anyway, the jstack execution produced the following error for every thread:

Thread 5674: (state = BLOCKED) Error occurred during stack walking: sun.jvm.hotspot.debugger.DebuggerException: sun.jvm.hotspot.debugger.DebuggerException: get_thread_regs failed for a lwp

If you want "talk" to me directly you can find me on IRC #glassfish.

Note: I submitted the domain.xml and the NB project deployed with the web service described. The test i'm executing is opening three firefox tabs at

http://semlocal:8080/WSPruebaService/WSPrueba?Tester

and clicking on "espera5Mintuos" in each tab.

glassfishrobot commented 17 years ago

@glassfishrobot Commented mk111283 said: Couldn't reproduce so far. I'll try it out on the latest nightly build

glassfishrobot commented 17 years ago

@glassfishrobot Commented mk111283 said: Couldn't reproduce so far. I'll try it out on the latest nightly build

glassfishrobot commented 17 years ago

@glassfishrobot Commented mk111283 said: As mentioned earlier, this is not an ejb container bug.

I created a simple WebService (using a SLSB) similar to the submitter's example. I printed the thread id inside the business method of the bean. I then printed the Thread ID inside WebServiceInvocationHandler.invoke() method also and found that the WebServiceInvocationHandler's invoke method was never invoked by more than two thread concurrently. If more than two requests are made from a browser the third one blocks util the first one completes.

It is to be noted that whenever the WebServiceInvocationHandler.invoke() is executed, then immediately the println from the bean's busines method is printed. This clearly proves that EJBContainer allows concurrent threads. (Also SPECj benchmark heavily uses stateless session beans and this had never been an issue).

I am assigning this to the webservices team to analyze this.

glassfishrobot commented 17 years ago

@glassfishrobot Commented bhaktimehta said: I discussed this with Jean Francois and he cited that "From the bug description, opening 3 requests from Firefox to the same domain (glassfish) will never works as Firefox and IE limits the number of request to 2. You will get the same "problem" if you open two http connection. This is a recommendation from the http spec. That's will explain why standalone test works. "

I looked through the Http spec and found this in sec 8.1.4 "Clients that use persistent connections SHOULD limit the number of simultaneous connections that they maintain to a given server. A single-user client SHOULD NOT maintain more than 2 connections with any server or proxy" http://www.rfc-ref.org/RFC-TEXTS/2616/chapter8.html#sub1 So this is not a bug

glassfishrobot commented 17 years ago

@glassfishrobot Commented File: AsynchWS1.tgz Attached By: andresgr

glassfishrobot commented 17 years ago

@glassfishrobot Commented File: domain.xml Attached By: andresgr

glassfishrobot commented 17 years ago

@glassfishrobot Commented File: server.log.txt Attached By: andresgr

glassfishrobot commented 17 years ago

@glassfishrobot Commented Was assigned to bhaktimehta

glassfishrobot commented 7 years ago

@glassfishrobot Commented This issue was imported from java.net JIRA GLASSFISH-2870

glassfishrobot commented 17 years ago

@glassfishrobot Commented Reported by andresgr

glassfishrobot commented 17 years ago

@glassfishrobot Commented Marked as incomplete on Tuesday, June 26th 2007, 7:27:50 am

eclipse-ee4j / glassfish

SLSBs pooling not working as expected #2870

Environment

Affected Versions