Everything seems to happen twice

Imported from Google Groups
1

Since the beginning of my project it seems that everything happens twice, and I don’t know why. Look at this log, what could be wrong?

19 Apr 2014 20:31:41 INFO ClassPathXmlApplicationContext - Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@1436e7a9: startup date [Sat Apr 19 20:31:41 CEST 2014]; root of context hierarchy
19 Apr 2014 20:31:41 INFO XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [spring-context.xml]
19 Apr 2014 20:31:41 INFO AutowiredAnnotationBeanPostProcessor - JSR-330 ‘javax.inject.Inject’ annotation found and supported for autowiring
19 Apr 2014 20:31:41 INFO PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean ‘(inner bean)’ of type [class org.axonframework.contextsupport.spring.SpringContextParameterResolverFactoryBuilder$ClasspathParameterResolverFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
19 Apr 2014 20:31:41 INFO PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean ‘(inner bean)’ of type [class org.axonframework.common.annotation.ClasspathParameterResolverFactory] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
19 Apr 2014 20:31:41 INFO PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean ‘(inner bean)#1’ of type [class org.axonframework.common.annotation.SpringBeanParameterResolverFactory] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
19 Apr 2014 20:31:41 INFO PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean ‘__axon-parameter-resolver-factory’ of type [class org.axonframework.contextsupport.spring.ApplicationContextLookupParameterResolverFactory] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
19 Apr 2014 20:31:41 INFO PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean ‘__axon-parameter-resolver-factory’ of type [class org.axonframework.common.annotation.MultiParameterResolverFactory] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
19 Apr 2014 20:31:41 INFO ChainingConverterFactory - ContentTypeConverter of type [class org.axonframework.serializer.xml.Dom4JToByteArrayConverter] is ignored. It seems to rely on a class that is not available in the class loader: org/dom4j/Document
19 Apr 2014 20:31:41 INFO ChainingConverterFactory - ContentTypeConverter of type [class org.axonframework.serializer.xml.InputStreamToDom4jConverter] is ignored. It seems to rely on a class that is not available in the class loader: org/dom4j/Document
19 Apr 2014 20:31:42 INFO ThreadPoolTaskExecutor - Initializing ExecutorService ‘taskExecutor’
19 Apr 2014 20:31:42 INFO DefaultLifecycleProcessor - Starting beans in phase 0
19 Apr 2014 20:31:42 DEBUG PurchaseOrderEventHandler - ***** TransportOrderSentEvent FIRED, id: 123
19 Apr 2014 20:31:42 DEBUG PurchaseOrderEventHandler - ***** TransportOrderSentEvent FIRED, id: 123
19 Apr 2014 20:31:42 INFO SupplierSaga - ************ SupplierSaga handle TransportOrderSentEvent
19 Apr 2014 20:31:42 INFO SupplierSaga - ************ SupplierSaga handle TransportOrderSentEvent
19 Apr 2014 20:31:42 INFO ClassPathXmlApplicationContext - Closing org.springframework.context.support.ClassPathXmlApplicationContext@1436e7a9: startup date [Sat Apr 19 20:31:41 CEST 2014]; root of context hierarchy
19 Apr 2014 20:31:42 INFO DefaultLifecycleProcessor - Stopping beans in phase 0
19 Apr 2014 20:31:42 INFO ThreadPoolTaskExecutor - Shutting down ExecutorService ‘taskExecutor’

This was the result after running the following code:

public class RunSupplierSaga {

@SuppressWarnings(“unchecked”)
public static void main(String[] args) throws InterruptedException {
ClassPathXmlApplicationContext applicationContext = new ClassPathXmlApplicationContext(“spring-context.xml”);

EventBus eventBus = applicationContext.getBean(EventBus.class);

eventBus.publish(asEventMessage(new TransportOrderSentEvent(“123”)));

applicationContext.close();
}
}

…meaning, ONE TransportOrderSentEvent published on the eventBus, but everything caused by this event seems to happen twice…or, am I fooled by logging output somehow?

2

It certainly looks like it’s just logging it twice. What’s the logging configuration look like? Did you put an additivity flag in there somewhere?

3

Hi, the log4 looks like this:

<?xml version="1.0" encoding="UTF-8" ?>

<log4j:configuration debug=“true”
xmlns:log4j=‘http://jakarta.apache.org/log4j/’>

4

You could try to run it in debug mode, and set a break point. Does it really reach the code twice?
You could also check whether the beans have somehow been registered twice with the EventBus. Normally, you can’t do that, but when two different proxies are created, it’s theoretically possible.

Cheers,

Allard

5

I debugged the classes, and they are only accessed once, so there must be some logging issues. Annoying, but now I at least know that my code is working as expected :slight_smile:

Any input on why it logs each statement twice?

6

This can be marked as case closed as well! I had a log4j.xml in src/test/resources, and I replaced it with a log4j.properties similar to the one found in Axon tutorial, and it logs like it should. Don’t care to look into why my old log4j.xml logged twice, more than happy to have the log4j.properties :slight_smile: