You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@uima.apache.org by Jörn Kottmann <ko...@gmail.com> on 2009/08/26 14:23:09 UTC
UIMA AS client CPU load
Hi everyone,
to put some load on one of our UIMA AS system I wrote
a small tool which uses the client API to send CASes to
a processing pipeline.
This tool has an endless loop which waits for work
to arrive and then sends it to the processing pipeline.
It basically looks like this:
text = getNextDocument() // returns plain text which should be analyzed
CAS cas = uimASEngine.getCAS();
cas.setDocumentText(text)
uimaAsEngine.sendCAS(cas)
When the tool is started there is usually lots of work waiting
and all available CASes are sent out to the service. It takes a while
until the first CAS is completly processed. Now the
tool gets a new text and waits for a new CAS inside getCAS().
Now I wonder why waiting for a CAS inside getCAS() puts 95 to 100 % CPU
load
on one core on my client machine.
I looked at the place where it waits in
BaseUIMAAsynchronousEngineCommon_impl
around line 536 in getCAS().
Here is the wait loop:
while (running) {
try {
// Wait until the CAS producer adds the CAS to the
CasQueueEntry and
// signals CAS availability.
entry.getSemaphore().acquire();
if (entry.getCas() == null) {
continue;
} else {
return entry.getCas();
}
} finally {
entry.getSemaphore().release();
}
} // while
For me it looks like that if entry.getCAS() returns null it immediately
tries again and polls entry.getCAS() as often as possible.
Jörn
Re: UIMA AS client CPU load
Posted by Jaroslaw Cwiklik <ui...@gmail.com>.
Jorn, I've added a new testcase that is based on what you've described your
client does. It was added to the
TestUimaASExtended.java in the uimaj-as-activemq project. The name of the
testcase: testClientProcess().
I can send 100 CASes to a service with no problem. Can you check the source
of the testcase and tell me how it differs from your code.
Thanks, Jerry
On Wed, Sep 2, 2009 at 4:22 AM, Jörn Kottmann <ko...@gmail.com> wrote:
> Jaroslaw Cwiklik wrote:
>
>> Jorn, I took Burn's suggestion and removed a busy loop from the getCas().
>> Instead of waiting between retries I use a semaphore to signal
>> availability of a CAS. Not sure what this hang is all about. Can you
>> refresh
>> all projects from the svn and try again.
>>
>>
> The refresh removed a bunch of classes and updated the loop
> from wait to semaphore.
>
> The application now fails non deterministic.
>
> Here is the piece of the loop in which it fails:
> CAS cas = uimaAsEngine.getCAS();
> cas.setDocumentText(Bytes.toString(result.getRow()));
>
> There are two different erros I get, either
>
> Exception in thread "main" org.apache.uima.cas.CASRuntimeException: Data
> for Sofa feature setLocalSofaData(String) has already been set.
> at
> org.apache.uima.cas.impl.SofaFSImpl.setLocalSofaData(SofaFSImpl.java:105)
> at org.apache.uima.cas.impl.CASImpl.setSofaDataString(CASImpl.java:4102)
> at org.apache.uima.cas.impl.CASImpl.setDocumentText(CASImpl.java:4087)
> at Retag.main(Retag.java:89)
>
> or
>
> Exception in thread "main" java.lang.NullPointerException
> at Retag.main(Retag.java:89)
>
> The second one appears to occur especially if there is a breakpoint at
> getCas().
>
> Jörn
>
Re: UIMA AS client CPU load
Posted by Jörn Kottmann <ko...@gmail.com>.
Jaroslaw Cwiklik wrote:
> Jorn, I took Burn's suggestion and removed a busy loop from the getCas().
> Instead of waiting between retries I use a semaphore to signal
> availability of a CAS. Not sure what this hang is all about. Can you refresh
> all projects from the svn and try again.
>
The refresh removed a bunch of classes and updated the loop
from wait to semaphore.
The application now fails non deterministic.
Here is the piece of the loop in which it fails:
CAS cas = uimaAsEngine.getCAS();
cas.setDocumentText(Bytes.toString(result.getRow()));
There are two different erros I get, either
Exception in thread "main" org.apache.uima.cas.CASRuntimeException: Data
for Sofa feature setLocalSofaData(String) has already been set.
at
org.apache.uima.cas.impl.SofaFSImpl.setLocalSofaData(SofaFSImpl.java:105)
at org.apache.uima.cas.impl.CASImpl.setSofaDataString(CASImpl.java:4102)
at org.apache.uima.cas.impl.CASImpl.setDocumentText(CASImpl.java:4087)
at Retag.main(Retag.java:89)
or
Exception in thread "main" java.lang.NullPointerException
at Retag.main(Retag.java:89)
The second one appears to occur especially if there is a breakpoint at
getCas().
Jörn
Re: UIMA AS client CPU load
Posted by Jaroslaw Cwiklik <ui...@gmail.com>.
Jorn, I took Burn's suggestion and removed a busy loop from the getCas().
Instead of waiting between retries I use a semaphore to signal
availability of a CAS. Not sure what this hang is all about. Can you refresh
all projects from the svn and try again.
Thanks
On Tue, Sep 1, 2009 at 12:03 PM, Jörn Kottmann <ko...@gmail.com> wrote:
> Jaroslaw Cwiklik wrote:
>
>> Jorn, I've fixed this under UIMA-1540. Let me know if this fixes the
>> problem.
>>
>>
> Yeah, tried to build it, but it the tests hang here:
>
> +------------------------------------------------------------------
> Sep 1, 2009 5:54:13 PM
> org.apache.uima.aae.controller.BaseAnalysisEngineController logPlatformInfo
> INFO:
> +------------------------------------------------------------------
> Starting UIMA AS Service - PID:20891
> +------------------------------------------------------------------
> + Service Name:Person Title Annotator
> + Service Queue Name:PersonTitleAnnotatorQueue
> + Service Start Time:01 Sep 2009 17:54:05
> + UIMA AS Version:2.3.0
> + UIMA Core Version:2.3.0
> + OS Name:Linux
> + OS Version:2.6.28-15-generic
> + OS Architecture:i386
> + OS CPU Count:2
> + JVM Vendor:Sun Microsystems Inc.
> + JVM Name:Java HotSpot(TM) Server VM
> + JVM Version:14.0-b16
> + JVM Input Args:[-Xmx300M]
> + JVM Classpath:/usr/share/maven2/boot/classworlds.jar
> + JVM
> LIB_PATH:/usr/lib/jvm/java-6-sun-1.6.0.14/jre/lib/i386/server:/usr/lib/jvm/java-6-sun-1.6.0.14/jre/lib/i386:/usr/lib/jvm/java-6-sun-1.6.0.14/jre/../lib/i386:/usr/java/packages/lib/i386:/lib:/usr/lib
> +------------------------------------------------------------------
> Sep 1, 2009 5:54:13 PM org.apache.uima.adapter.jms.activemq.JmsInputChannel
> setEndpointName
> INFO: top_level_input_queue_service_1 Service Starting - Listening for
> Messages
> Sep 1, 2009 5:54:13 PM
> org.apache.uima.adapter.jms.activemq.SpringContainerDeployer
> waitForServiceNotification
> INFO: Uima EE Client Blocking - Awaiting Top Level Controller
> Initialization Notification
> Service:Person Title Annotator Listener Ready. Broker:tcp://localhost:8118
> Queue:queue://PersonTitleAnnotatorQueue Selector:Command=2000 OR
> Command=2002
> Service:Person Title Annotator Listener Ready. Broker:tcp://localhost:8118
> Queue:queue://PersonTitleAnnotatorQueue Selector:Command=2001
> CasManager Initialized Cas Pool:PrimitiveAEService. Cas Pool Size:5 Initial
> Cas Heap Size:500000 cells
> Service:Person Title Annotator Initialized. Ready To Process Messages From
> Queue:PersonTitleAnnotatorQueue
> Sep 1, 2009 5:54:14 PM
> org.apache.uima.aae.controller.PrimitiveAnalysisEngineController_impl
> initialize
> INFO: ********* Initialized the Controller. Person Title Annotator Ready To
> Process. ********
> Sep 1, 2009 5:54:14 PM
> org.apache.uima.adapter.jms.client.BaseUIMAAsynchronousEngine_impl
> setupConnection
> INFO: UIMA AS Client Created Shared Connection To Broker:
> tcp://karkand:8118
> UIMA AS Client Created Shared Connection To Broker:tcp://karkand:8118
> Sep 1, 2009 5:54:14 PM
> org.apache.uima.adapter.jms.client.BaseUIMAAsynchronousEngine_impl
> initializeProducer
> INFO: Initializing JMS Message Producer. Broker: tcp://karkand:8118 Queue
> Name: PersonTitleAnnotatorQueue
> Sep 1, 2009 5:54:14 PM
> org.apache.uima.adapter.jms.client.BaseUIMAAsynchronousEngine_impl
> initializeConsumer
> INFO: Initializing JMS Message Consumer. Broker: tcp://karkand:8118 Queue
> Name: ID:karkand-56803-1251820447466-3:2:1
> >>>> Client Activated Temp Reply Queue:ID:karkand-56803-1251820447466-3:2:1
> Sep 1, 2009 5:54:15 PM
> org.apache.uima.adapter.jms.client.BaseUIMAAsynchronousEngine_impl
> initialize
> INFO: Asynchronous Client Has Been Initialized. Serialization Strategy:
> [xmi] Ready To Process.
> First Initialize Call Completed
> Received Expected Exception:class
> org.apache.uima.UIMA_IllegalStateException
>
Re: UIMA AS client CPU load
Posted by Jörn Kottmann <ko...@gmail.com>.
Jaroslaw Cwiklik wrote:
> Jorn, I've fixed this under UIMA-1540. Let me know if this fixes the
> problem.
>
Yeah, tried to build it, but it the tests hang here:
+------------------------------------------------------------------
Sep 1, 2009 5:54:13 PM
org.apache.uima.aae.controller.BaseAnalysisEngineController logPlatformInfo
INFO:
+------------------------------------------------------------------
Starting UIMA AS Service - PID:20891
+------------------------------------------------------------------
+ Service Name:Person Title Annotator
+ Service Queue Name:PersonTitleAnnotatorQueue
+ Service Start Time:01 Sep 2009 17:54:05
+ UIMA AS Version:2.3.0
+ UIMA Core Version:2.3.0
+ OS Name:Linux
+ OS Version:2.6.28-15-generic
+ OS Architecture:i386
+ OS CPU Count:2
+ JVM Vendor:Sun Microsystems Inc.
+ JVM Name:Java HotSpot(TM) Server VM
+ JVM Version:14.0-b16
+ JVM Input Args:[-Xmx300M]
+ JVM Classpath:/usr/share/maven2/boot/classworlds.jar
+ JVM
LIB_PATH:/usr/lib/jvm/java-6-sun-1.6.0.14/jre/lib/i386/server:/usr/lib/jvm/java-6-sun-1.6.0.14/jre/lib/i386:/usr/lib/jvm/java-6-sun-1.6.0.14/jre/../lib/i386:/usr/java/packages/lib/i386:/lib:/usr/lib
+------------------------------------------------------------------
Sep 1, 2009 5:54:13 PM
org.apache.uima.adapter.jms.activemq.JmsInputChannel setEndpointName
INFO: top_level_input_queue_service_1 Service Starting - Listening for
Messages
Sep 1, 2009 5:54:13 PM
org.apache.uima.adapter.jms.activemq.SpringContainerDeployer
waitForServiceNotification
INFO: Uima EE Client Blocking - Awaiting Top Level Controller
Initialization Notification
Service:Person Title Annotator Listener Ready.
Broker:tcp://localhost:8118 Queue:queue://PersonTitleAnnotatorQueue
Selector:Command=2000 OR Command=2002
Service:Person Title Annotator Listener Ready.
Broker:tcp://localhost:8118 Queue:queue://PersonTitleAnnotatorQueue
Selector:Command=2001
CasManager Initialized Cas Pool:PrimitiveAEService. Cas Pool Size:5
Initial Cas Heap Size:500000 cells
Service:Person Title Annotator Initialized. Ready To Process Messages
From Queue:PersonTitleAnnotatorQueue
Sep 1, 2009 5:54:14 PM
org.apache.uima.aae.controller.PrimitiveAnalysisEngineController_impl
initialize
INFO: ********* Initialized the Controller. Person Title Annotator Ready
To Process. ********
Sep 1, 2009 5:54:14 PM
org.apache.uima.adapter.jms.client.BaseUIMAAsynchronousEngine_impl
setupConnection
INFO: UIMA AS Client Created Shared Connection To Broker: tcp://karkand:8118
UIMA AS Client Created Shared Connection To Broker:tcp://karkand:8118
Sep 1, 2009 5:54:14 PM
org.apache.uima.adapter.jms.client.BaseUIMAAsynchronousEngine_impl
initializeProducer
INFO: Initializing JMS Message Producer. Broker: tcp://karkand:8118
Queue Name: PersonTitleAnnotatorQueue
Sep 1, 2009 5:54:14 PM
org.apache.uima.adapter.jms.client.BaseUIMAAsynchronousEngine_impl
initializeConsumer
INFO: Initializing JMS Message Consumer. Broker: tcp://karkand:8118
Queue Name: ID:karkand-56803-1251820447466-3:2:1
>>>> Client Activated Temp Reply Queue:ID:karkand-56803-1251820447466-3:2:1
Sep 1, 2009 5:54:15 PM
org.apache.uima.adapter.jms.client.BaseUIMAAsynchronousEngine_impl
initialize
INFO: Asynchronous Client Has Been Initialized. Serialization Strategy:
[xmi] Ready To Process.
First Initialize Call Completed
Received Expected Exception:class org.apache.uima.UIMA_IllegalStateException
Re: UIMA AS client CPU load
Posted by Jaroslaw Cwiklik <ui...@gmail.com>.
Jorn, I've fixed this under UIMA-1540. Let me know if this fixes the
problem.
Thanks for pointing this out.
Jerry
On Tue, Sep 1, 2009 at 8:26 AM, Jörn Kottmann <ko...@gmail.com> wrote:
> Posted it a few days ago, would be nice if someone
> could have a look. I assume there is a wait missing, right ?
> If so the fix is simple and we can include it in 2.3.0.
>
> Jörn
>
>
> Jörn Kottmann wrote:
>
>> Hi everyone,
>>
>> to put some load on one of our UIMA AS system I wrote
>> a small tool which uses the client API to send CASes to
>> a processing pipeline.
>>
>> This tool has an endless loop which waits for work
>> to arrive and then sends it to the processing pipeline.
>>
>> It basically looks like this:
>>
>> text = getNextDocument() // returns plain text which should be analyzed
>>
>> CAS cas = uimASEngine.getCAS();
>> cas.setDocumentText(text)
>> uimaAsEngine.sendCAS(cas)
>>
>> When the tool is started there is usually lots of work waiting
>> and all available CASes are sent out to the service. It takes a while
>> until the first CAS is completly processed. Now the
>> tool gets a new text and waits for a new CAS inside getCAS().
>>
>> Now I wonder why waiting for a CAS inside getCAS() puts 95 to 100 % CPU
>> load
>> on one core on my client machine.
>>
>> I looked at the place where it waits in
>> BaseUIMAAsynchronousEngineCommon_impl
>> around line 536 in getCAS().
>>
>> Here is the wait loop:
>> while (running) {
>> try {
>> // Wait until the CAS producer adds the CAS to the CasQueueEntry
>> and
>> // signals CAS availability.
>> entry.getSemaphore().acquire();
>> if (entry.getCas() == null) {
>> continue;
>> } else {
>> return entry.getCas();
>> }
>> } finally {
>> entry.getSemaphore().release();
>> } } // while
>>
>> For me it looks like that if entry.getCAS() returns null it immediately
>> tries again and polls entry.getCAS() as often as possible.
>>
>> Jörn
>>
>>
>
Re: UIMA AS client CPU load
Posted by Jörn Kottmann <ko...@gmail.com>.
Posted it a few days ago, would be nice if someone
could have a look. I assume there is a wait missing, right ?
If so the fix is simple and we can include it in 2.3.0.
Jörn
Jörn Kottmann wrote:
> Hi everyone,
>
> to put some load on one of our UIMA AS system I wrote
> a small tool which uses the client API to send CASes to
> a processing pipeline.
>
> This tool has an endless loop which waits for work
> to arrive and then sends it to the processing pipeline.
>
> It basically looks like this:
>
> text = getNextDocument() // returns plain text which should be analyzed
>
> CAS cas = uimASEngine.getCAS();
> cas.setDocumentText(text)
> uimaAsEngine.sendCAS(cas)
>
> When the tool is started there is usually lots of work waiting
> and all available CASes are sent out to the service. It takes a while
> until the first CAS is completly processed. Now the
> tool gets a new text and waits for a new CAS inside getCAS().
>
> Now I wonder why waiting for a CAS inside getCAS() puts 95 to 100 %
> CPU load
> on one core on my client machine.
>
> I looked at the place where it waits in
> BaseUIMAAsynchronousEngineCommon_impl
> around line 536 in getCAS().
>
> Here is the wait loop:
> while (running) {
> try {
> // Wait until the CAS producer adds the CAS to the
> CasQueueEntry and
> // signals CAS availability.
> entry.getSemaphore().acquire();
> if (entry.getCas() == null) {
> continue;
> } else {
> return entry.getCas();
> }
> } finally {
> entry.getSemaphore().release();
> } } // while
>
> For me it looks like that if entry.getCAS() returns null it immediately
> tries again and polls entry.getCAS() as often as possible.
>
> Jörn
>