Petals SE POJO

An error 'IllegalStateException' occurs in the POJO service provider when a timeout occurs waiting the response of an external service provider

Details

  • Type: Bug Bug
  • Status: Resolved Resolved
  • Priority: Blocker Blocker
  • Resolution: Fixed
  • Affects Version/s: 2.6.0, 2.7.0
  • Fix Version/s: 2.6.1, 2.7.1
  • Component/s: None
  • Security Level: Public
  • Description:
    Hide

    The following error occurs in the POJO service provider when a timeout occurs waiting the response to an external service provider call:

    2024/02/29 15:58:59,811 GMT+0100 MONIT [Petals.Container.Components.petals-se-pojo] :  traceCode = 'provideFlowStepBegin', flowInstanceId = '11cbbf60-d713-11ee-8deb-024200dc0afc', flowStepId = '11ccd0d0-d713-11ee-8deb-024200dc0afc', flowStepInterfaceName = '{http://petals.ow2.org/se/pojo/unit-test/pojo}Pojo', flowStepServiceName = '{http://petals.ow2.org/se/pojo/unit-test/pojo}PojoService', flowStepOperationName = '{http://petals.ow2.org/se/pojo/unit-test/pojo}executeAsync', flowStepEndpointName = 'PojoEndpointName', flowPreviousStepId = '11cbbf61-d713-11ee-8deb-024200dc0afc'
    2024/02/29 15:58:59,812 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Intercepting message processing on ACCEPT
    2024/02/29 15:58:59,813 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Processing 'executeAsync'.
    2024/02/29 15:58:59,821 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Timeout used for asynchronous call: 5000
    2024/02/29 15:58:59,822 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Add AsyncContext (as consumer) for exchange petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:58:59,822 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Send an asynchronous exchange with id : petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:58:59,823 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Intercepting message processing on SEND
    2024/02/29 15:58:59,825 GMT+0100 MONIT [org.ow2.petals.component.framework.UnderTestWithDefaultConf external-services] :  traceCode = 'provideFlowStepBegin', flowInstanceId = '11cbbf60-d713-11ee-8deb-024200dc0afc', flowStepId = '11cfde10-d713-11ee-8deb-024200dc0afc', flowStepInterfaceName = '{http://petals.ow2.org/se/pojo/unit-test/echo}Echo', flowStepServiceName = '{http://petals.ow2.org/se/pojo/unit-test/echo}EchoService', flowStepOperationName = '{http://petals.ow2.org/se/pojo/unit-test/echo}echo', flowStepEndpointName = 'EchoEndpointName', flowPreviousStepId = '11ccd0d0-d713-11ee-8deb-024200dc0afc'
    2024/02/29 15:59:05,757 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Expiration of async send for exchange id: petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:05,758 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Process an expired (sendAsync) exchange as CONSUMES with id : petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:05,761 GMT+0100 WARNING [Petals.Container.Components.petals-se-pojo] : An error occured during message processing, let's send it back since the exchange was active before.
    java.lang.IllegalStateException: The component does not owns the MessageExchange
    	at org.ow2.petals.jbi.messaging.exchange.MessageExchangeWrapper.checkComponentOwnsExchange(MessageExchangeWrapper.java:282)
    	at org.ow2.petals.jbi.messaging.exchange.MessageExchangeWrapper.getEndpoint(MessageExchangeWrapper.java:93)
    	at org.ow2.petals.component.framework.message.ExchangeImpl.getEndpointName(ExchangeImpl.java:175)
    	at org.ow2.petals.se.pojo.listener.JBIListener.onExpiredAsyncJBIMessage(JBIListener.java:133)
    	at org.ow2.petals.component.framework.process.MessageExchangeProcessor.processExpired(MessageExchangeProcessor.java:444)
    	at org.ow2.petals.component.framework.process.MessageExchangeProcessor.run(MessageExchangeProcessor.java:180)
    	at org.ow2.petals.component.framework.process.JBIProcessorThreadPoolExecutor$ExchangeRunnable.run(JBIProcessorThreadPoolExecutor.java:90)
    	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    	at java.base/java.lang.Thread.run(Thread.java:840)
    	at org.ow2.petals.component.framework.process.JBIProcessorThreadFactory$JBIProcessorThread.run(JBIProcessorThreadFactory.java:99)
    2024/02/29 15:59:05,761 GMT+0100 SEVERE [Petals.Container.Components.petals-se-pojo] : It seems I'm not the owner of the exchange anymore... Maybe there is a bug somewhere! There is nothing I can do now.
    java.lang.IllegalStateException: The component does not owns the MessageExchange
    	at org.ow2.petals.jbi.messaging.exchange.MessageExchangeWrapper.checkComponentOwnsExchange(MessageExchangeWrapper.java:282)
    	at org.ow2.petals.jbi.messaging.exchange.MessageExchangeWrapper.setError(MessageExchangeWrapper.java:194)
    	at org.ow2.petals.component.framework.message.ExchangeImpl.setError(ExchangeImpl.java:593)
    	at org.ow2.petals.component.framework.process.MessageExchangeProcessor.run(MessageExchangeProcessor.java:191)
    	at org.ow2.petals.component.framework.process.JBIProcessorThreadPoolExecutor$ExchangeRunnable.run(JBIProcessorThreadPoolExecutor.java:90)
    	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    	at java.base/java.lang.Thread.run(Thread.java:840)
    	at org.ow2.petals.component.framework.process.JBIProcessorThreadFactory$JBIProcessorThread.run(JBIProcessorThreadFactory.java:99)
    2024/02/29 15:59:07,330 GMT+0100 MONIT [org.ow2.petals.component.framework.UnderTestWithDefaultConf external-services] :  traceCode = 'provideFlowStepEnd', flowInstanceId = '11cbbf60-d713-11ee-8deb-024200dc0afc', flowStepId = '11cfde10-d713-11ee-8deb-024200dc0afc'
    2024/02/29 15:59:07,337 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Accepting a JBI message with Id : petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:07,340 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Remove AsyncContext (as consumer) for exchange petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:07,342 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Retrieved consumer flow attributes (Flow[instance=11cbbf60-d713-11ee-8deb-024200dc0afc, step=11ccd0d0-d713-11ee-8deb-024200dc0afc]) from exchange (petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc)
    2024/02/29 15:59:07,343 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Flow attributes for exchange (id petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc) set to Flow[instance=11cbbf60-d713-11ee-8deb-024200dc0afc, step=11ccd0d0-d713-11ee-8deb-024200dc0afc]
    2024/02/29 15:59:07,345 GMT+0100 INFO [Petals.Container.Components.petals-se-pojo] : The asynchronous response does not match any AsyncContext for petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc. It must have expired before: let's notify the sender with an error.
    2024/02/29 15:59:07,345 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Send an asynchronous exchange with id : petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:07,346 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Intercepting message processing on SEND
    Show
    The following error occurs in the POJO service provider when a timeout occurs waiting the response to an external service provider call:
    2024/02/29 15:58:59,811 GMT+0100 MONIT [Petals.Container.Components.petals-se-pojo] :  traceCode = 'provideFlowStepBegin', flowInstanceId = '11cbbf60-d713-11ee-8deb-024200dc0afc', flowStepId = '11ccd0d0-d713-11ee-8deb-024200dc0afc', flowStepInterfaceName = '{http://petals.ow2.org/se/pojo/unit-test/pojo}Pojo', flowStepServiceName = '{http://petals.ow2.org/se/pojo/unit-test/pojo}PojoService', flowStepOperationName = '{http://petals.ow2.org/se/pojo/unit-test/pojo}executeAsync', flowStepEndpointName = 'PojoEndpointName', flowPreviousStepId = '11cbbf61-d713-11ee-8deb-024200dc0afc'
    2024/02/29 15:58:59,812 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Intercepting message processing on ACCEPT
    2024/02/29 15:58:59,813 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Processing 'executeAsync'.
    2024/02/29 15:58:59,821 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Timeout used for asynchronous call: 5000
    2024/02/29 15:58:59,822 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Add AsyncContext (as consumer) for exchange petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:58:59,822 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Send an asynchronous exchange with id : petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:58:59,823 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Intercepting message processing on SEND
    2024/02/29 15:58:59,825 GMT+0100 MONIT [org.ow2.petals.component.framework.UnderTestWithDefaultConf external-services] :  traceCode = 'provideFlowStepBegin', flowInstanceId = '11cbbf60-d713-11ee-8deb-024200dc0afc', flowStepId = '11cfde10-d713-11ee-8deb-024200dc0afc', flowStepInterfaceName = '{http://petals.ow2.org/se/pojo/unit-test/echo}Echo', flowStepServiceName = '{http://petals.ow2.org/se/pojo/unit-test/echo}EchoService', flowStepOperationName = '{http://petals.ow2.org/se/pojo/unit-test/echo}echo', flowStepEndpointName = 'EchoEndpointName', flowPreviousStepId = '11ccd0d0-d713-11ee-8deb-024200dc0afc'
    2024/02/29 15:59:05,757 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Expiration of async send for exchange id: petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:05,758 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Process an expired (sendAsync) exchange as CONSUMES with id : petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:05,761 GMT+0100 WARNING [Petals.Container.Components.petals-se-pojo] : An error occured during message processing, let's send it back since the exchange was active before.
    java.lang.IllegalStateException: The component does not owns the MessageExchange
    	at org.ow2.petals.jbi.messaging.exchange.MessageExchangeWrapper.checkComponentOwnsExchange(MessageExchangeWrapper.java:282)
    	at org.ow2.petals.jbi.messaging.exchange.MessageExchangeWrapper.getEndpoint(MessageExchangeWrapper.java:93)
    	at org.ow2.petals.component.framework.message.ExchangeImpl.getEndpointName(ExchangeImpl.java:175)
    	at org.ow2.petals.se.pojo.listener.JBIListener.onExpiredAsyncJBIMessage(JBIListener.java:133)
    	at org.ow2.petals.component.framework.process.MessageExchangeProcessor.processExpired(MessageExchangeProcessor.java:444)
    	at org.ow2.petals.component.framework.process.MessageExchangeProcessor.run(MessageExchangeProcessor.java:180)
    	at org.ow2.petals.component.framework.process.JBIProcessorThreadPoolExecutor$ExchangeRunnable.run(JBIProcessorThreadPoolExecutor.java:90)
    	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    	at java.base/java.lang.Thread.run(Thread.java:840)
    	at org.ow2.petals.component.framework.process.JBIProcessorThreadFactory$JBIProcessorThread.run(JBIProcessorThreadFactory.java:99)
    2024/02/29 15:59:05,761 GMT+0100 SEVERE [Petals.Container.Components.petals-se-pojo] : It seems I'm not the owner of the exchange anymore... Maybe there is a bug somewhere! There is nothing I can do now.
    java.lang.IllegalStateException: The component does not owns the MessageExchange
    	at org.ow2.petals.jbi.messaging.exchange.MessageExchangeWrapper.checkComponentOwnsExchange(MessageExchangeWrapper.java:282)
    	at org.ow2.petals.jbi.messaging.exchange.MessageExchangeWrapper.setError(MessageExchangeWrapper.java:194)
    	at org.ow2.petals.component.framework.message.ExchangeImpl.setError(ExchangeImpl.java:593)
    	at org.ow2.petals.component.framework.process.MessageExchangeProcessor.run(MessageExchangeProcessor.java:191)
    	at org.ow2.petals.component.framework.process.JBIProcessorThreadPoolExecutor$ExchangeRunnable.run(JBIProcessorThreadPoolExecutor.java:90)
    	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    	at java.base/java.lang.Thread.run(Thread.java:840)
    	at org.ow2.petals.component.framework.process.JBIProcessorThreadFactory$JBIProcessorThread.run(JBIProcessorThreadFactory.java:99)
    2024/02/29 15:59:07,330 GMT+0100 MONIT [org.ow2.petals.component.framework.UnderTestWithDefaultConf external-services] :  traceCode = 'provideFlowStepEnd', flowInstanceId = '11cbbf60-d713-11ee-8deb-024200dc0afc', flowStepId = '11cfde10-d713-11ee-8deb-024200dc0afc'
    2024/02/29 15:59:07,337 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Accepting a JBI message with Id : petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:07,340 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Remove AsyncContext (as consumer) for exchange petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:07,342 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Retrieved consumer flow attributes (Flow[instance=11cbbf60-d713-11ee-8deb-024200dc0afc, step=11ccd0d0-d713-11ee-8deb-024200dc0afc]) from exchange (petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc)
    2024/02/29 15:59:07,343 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Flow attributes for exchange (id petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc) set to Flow[instance=11cbbf60-d713-11ee-8deb-024200dc0afc, step=11ccd0d0-d713-11ee-8deb-024200dc0afc]
    2024/02/29 15:59:07,345 GMT+0100 INFO [Petals.Container.Components.petals-se-pojo] : The asynchronous response does not match any AsyncContext for petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc. It must have expired before: let's notify the sender with an error.
    2024/02/29 15:59:07,345 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Send an asynchronous exchange with id : petals:uid:11ce7e80-d713-11ee-8deb-024200dc0afc
    2024/02/29 15:59:07,346 GMT+0100 FINE [Petals.Container.Components.petals-se-pojo] : Intercepting message processing on SEND
  • Environment:
    -

Issue Links

Activity

Hide
Christophe DENEUX added a comment - Wed, 13 Mar 2024 - 11:18:49 +0100

Backported in branch petals-se-pojo-2.7.x with svn#45243

Show
Christophe DENEUX added a comment - Wed, 13 Mar 2024 - 11:18:49 +0100 Backported in branch petals-se-pojo-2.7.x with svn#45243
Hide
Christophe DENEUX added a comment - Tue, 5 Mar 2024 - 09:58:02 +0100

Backported in branch 2.6.x with svn#45219

Show
Christophe DENEUX added a comment - Tue, 5 Mar 2024 - 09:58:02 +0100 Backported in branch 2.6.x with svn#45219
Hide
Christophe DENEUX added a comment - Tue, 5 Mar 2024 - 09:24:02 +0100

Reopened to backport in branches 2.6.x and 2.7.x

Show
Christophe DENEUX added a comment - Tue, 5 Mar 2024 - 09:24:02 +0100 Reopened to backport in branches 2.6.x and 2.7.x
Hide
Christophe DENEUX added a comment - Tue, 5 Mar 2024 - 09:23:35 +0100

Fixed in trunk with svn#45216

Show
Christophe DENEUX added a comment - Tue, 5 Mar 2024 - 09:23:35 +0100 Fixed in trunk with svn#45216

People

Dates

  • Created:
    Thu, 29 Feb 2024 - 16:03:14 +0100
    Updated:
    Wed, 13 Mar 2024 - 11:19:02 +0100
    Resolved:
    Wed, 13 Mar 2024 - 11:18:49 +0100