Metadata sync failing in 2.40.3

Support - Assistance technique
,
1

Hello @team,
I am trying to run Metadata synchronisation job. I am getting repeated errors like this in my dhis.log file
Any insights on this?

  • INFO 2024-04-10T13:00:00,006 AMQ601767: CORE connection db514b28-f731-11ee-8c82-0242ac110003 for user unknown@invm:0 created (AuditLogger_impl.java [taskScheduler-18])

  • INFO 2024-04-10T13:00:00,006 AMQ601767: CORE connection db514b28-f731-11ee-8c82-0242ac110003 for user unknown@invm:0 created (AuditLogger_impl.java [taskScheduler-18])
    User anonymous@invm:0 sent a message CoreMessage[messageID=2459, durable=true, userID=7cc91af7-f72c-11ee-8c82-0242ac110003, priority=4, timestamp=Wed Apr 10 12:21:33 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1740, properties=TypedProperties[__AMQ_CID=7cc857a3-f72c-11ee-8c82-0242ac110003, _AMQ_ROUTING_TYPE=0]]@55670168, context: RoutingContextImpl(Address=dhis2.topic.metadata, routingType=MULTICAST, PreviousAddress=dhis2.topic.metadata previousRoute:MULTICAST, reusable=true, version=-2147483640)

  • INFO 2024-04-10T13:00:00,028 [META_DATA_SYNC jAV3TZn79CG] Stage started: Setting up metadata synchronisation (ControlledJobProgress.java [taskScheduler-18])

  • INFO 2024-04-10T13:00:00,028 [META_DATA_SYNC jAV3TZn79CG] Stage completed after 0.001s (ControlledJobProgress.java [taskScheduler-18])

  • INFO 2024-04-10T13:00:00,029 [META_DATA_SYNC jAV3TZn79CG] Process started: Starting DataValueSynchronization job (ControlledJobProgress.java [taskScheduler-18])

  • INFO 2024-04-10T13:00:00,201 [META_DATA_SYNC jAV3TZn79CG] Stage started: Counting data values (ControlledJobProgress.java [taskScheduler-18])

  • INFO 2024-04-10T13:00:00,203 [META_DATA_SYNC jAV3TZn79CG] Stage completed after 0.002s: DataValues last changed before Thu Jan 01 01:00:00 GMT 1970 will not be synchronized. (ControlledJobProgress.java [taskScheduler-18])

  • INFO 2024-04-10T13:00:00,204 [META_DATA_SYNC jAV3TZn79CG] Process completed after 0.175s: Skipping synchronization, no new or updated DataValues (ControlledJobProgress.java [taskScheduler-18])

  • INFO 2024-04-10T13:00:00,204 [META_DATA_SYNC jAV3TZn79CG] Process started: Starting Event programs data synchronization job. (ControlledJobProgress.java [taskScheduler-18])

  • INFO 2024-04-10T13:00:00,331 [META_DATA_SYNC jAV3TZn79CG] Stage started: Counting anonymous events ready to be synchronised. (ControlledJobProgress.java [taskScheduler-18])

  • WARN 2024-04-10T13:00:00,333 [META_DATA_SYNC jAV3TZn79CG] Process aborted after 0.306s: aborted after error: java.lang.NullPointerException (ControlledJobProgress.java [taskScheduler-18])

  • WARN 2024-04-10T13:00:00,333 [META_DATA_SYNC jAV3TZn79CG] Process aborted after 0.129s: aborted after error: java.lang.NullPointerException (ControlledJobProgress.java [taskScheduler-18])

  • ERROR 2024-04-10T13:00:00,333 [META_DATA_SYNC jAV3TZn79CG] Stage failed after 0.002s: java.lang.NullPointerException (ControlledJobProgress.java [taskScheduler-18])
    java.lang.NullPointerException: null
    at org.hisp.dhis.dxf2.events.event.JdbcEventStore.isUserSearchScopeNotSet(JdbcEventStore.java:1495)

2

Could it be related to the following note in the docs under the title “Configure metadata versioning on central instance”:

Note

To synchronize metadata, the user account of the central system must have the following authority:

F_METADATA_MANAGE

Only users with this authority will then be able to create and download metadata. This is to ensure security of the central system where the metadata is created. Instead of giving the credentials of user having ALL authority to the field instances, you need to create a user having this specific authority only

Thank you!

3

Hi @Gassim ,

But I only see F_EVENT_HOOK, F_ROUTE authority in metadata authorities. I tried both. Any idea where to add F_METADATA_MANAGE from?

Thanks

4

Is this the entire log displaying all the errors @Sweety_Sharma?

1 Like
5

Hi @moses_mwale @Gassim
Here is the entire log

* INFO  2024-04-11T07:06:57,730 Scheduler initiated execution of job: JobConfiguration{uid='jAV3TZn79CG', name='metadata sync', jobType=META_DATA_SYNC, cronExpression='0 0 * ? * *', delay='null', jobParameters=org.hisp.dhis.scheduling.parameters.MetadataSyncJobParameters@4d623666, enabled=true, inMemoryJob=false, lastRuntimeExecution='00:00:00.372', userUid='null', leaderOnlyJob=false, jobStatus=SCHEDULED, nextExecutionTime=null, lastExecutedStatus=STOPPED, lastExecuted=2024-04-11 07:00:00.002} (DefaultSchedulingManager.java [http-nio-8080-exec-6])
* INFO  2024-04-11T07:06:57,733 AMQ601767: CORE connection b41cafdc-f7c9-11ee-9506-0242ac110003 for user unknown@invm:0 created (AuditLogger_impl.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,733 AMQ601767: CORE connection b41cafdc-f7c9-11ee-9506-0242ac110003 for user unknown@invm:0 created (AuditLogger_impl.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,735 AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::name=localhost with parameters: [b41cfdff-f7c9-11ee-9506-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=b41cafdc-f7c9-11ee-9506-0242ac110003, clientID=null, nodeID=2d644d5d-f7c5-11ee-9506-0242ac110003, transportConnection=InVMConnection [serverID=0, id=b41cafdc-f7c9-11ee-9506-0242ac110003]], false, false, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@2424b3, true, {}] (AuditLogger_impl.java [Thread-2 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,735 AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::name=localhost with parameters: [b41cfdff-f7c9-11ee-9506-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=b41cafdc-f7c9-11ee-9506-0242ac110003, clientID=null, nodeID=2d644d5d-f7c5-11ee-9506-0242ac110003, transportConnection=InVMConnection [serverID=0, id=b41cafdc-f7c9-11ee-9506-0242ac110003]], false, false, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@2424b3, true, {}] (AuditLogger_impl.java [Thread-2 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,736 AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::name=localhost with parameters: [b41d2510-f7c9-11ee-9506-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=b41cafdc-f7c9-11ee-9506-0242ac110003, clientID=null, nodeID=2d644d5d-f7c5-11ee-9506-0242ac110003, transportConnection=InVMConnection [serverID=0, id=b41cafdc-f7c9-11ee-9506-0242ac110003]], true, true, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@16b190e8, true, {}] (AuditLogger_impl.java [Thread-5 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,736 AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::name=localhost with parameters: [b41d2510-f7c9-11ee-9506-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=b41cafdc-f7c9-11ee-9506-0242ac110003, clientID=null, nodeID=2d644d5d-f7c5-11ee-9506-0242ac110003, transportConnection=InVMConnection [serverID=0, id=b41cafdc-f7c9-11ee-9506-0242ac110003]], true, true, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@16b190e8, true, {}] (AuditLogger_impl.java [Thread-5 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,740 AMQ601501: User anonymous@invm:0 is consuming a message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: Reference[35184]:RELIABLE:CoreMessage[messageID=35184, durable=true, userID=b41d7331-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:57 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b41cfdfe-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@1224728746 (AuditLogger_impl.java [Thread-11 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,740 AMQ601501: User anonymous@invm:0 is consuming a message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: Reference[35184]:RELIABLE:CoreMessage[messageID=35184, durable=true, userID=b41d7331-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:57 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b41cfdfe-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@1224728746 (AuditLogger_impl.java [Thread-11 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,740 AMQ601500: User anonymous@invm:0 sent a message CoreMessage[messageID=35184, durable=true, userID=b41d7331-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:57 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b41cfdfe-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@1224728746, context: RoutingContextImpl(Address=dhis2.topic.metadata, routingType=MULTICAST, PreviousAddress=dhis2.topic.metadata previousRoute:MULTICAST, reusable=true, version=-2147483640)
..................................................
***** durable queues dhis2.topic.metadata:
***** non durable for dhis2.topic.metadata:
- queueID=104 address:dhis2.topic.metadata name:24038330-11ef-49a2-ac9f-d35d2464d8dd filter:null
..................................................
, transaction: null (AuditLogger_impl.java [Thread-1 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,740 AMQ601500: User anonymous@invm:0 sent a message CoreMessage[messageID=35184, durable=true, userID=b41d7331-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:57 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b41cfdfe-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@1224728746, context: RoutingContextImpl(Address=dhis2.topic.metadata, routingType=MULTICAST, PreviousAddress=dhis2.topic.metadata previousRoute:MULTICAST, reusable=true, version=-2147483640)
..................................................
***** durable queues dhis2.topic.metadata:
***** non durable for dhis2.topic.metadata:
- queueID=104 address:dhis2.topic.metadata name:24038330-11ef-49a2-ac9f-d35d2464d8dd filter:null
..................................................
, transaction: null (AuditLogger_impl.java [Thread-1 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,742 AMQ601759: User anonymous@invm:0 added acknowledgement of a message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: CoreMessage[messageID=35184, durable=true, userID=b41d7331-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:57 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b41cfdfe-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@1224728746 to transaction: TransactionImpl [xid=null, txID=35185, xid=null, state=ACTIVE, createTime=1712815617742(Thu Apr 11 07:06:57 BST 2024), timeoutSeconds=-1, nr operations = 1]@735ba633 (AuditLogger_impl.java [Thread-4 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,742 AMQ601759: User anonymous@invm:0 added acknowledgement of a message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: CoreMessage[messageID=35184, durable=true, userID=b41d7331-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:57 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b41cfdfe-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@1224728746 to transaction: TransactionImpl [xid=null, txID=35185, xid=null, state=ACTIVE, createTime=1712815617742(Thu Apr 11 07:06:57 BST 2024), timeoutSeconds=-1, nr operations = 1]@735ba633 (AuditLogger_impl.java [Thread-4 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,742 AMQ601502: User anonymous@invm:0 acknowledged message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: CoreMessage[messageID=35184, durable=true, userID=b41d7331-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:57 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b41cfdfe-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@1224728746, transaction: TransactionImpl [xid=null, txID=35185, xid=null, state=COMMITTED, createTime=1712815617742(Thu Apr 11 07:06:57 BST 2024), timeoutSeconds=-1, nr operations = 0]@735ba633 (AuditLogger_impl.java [Thread-4 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,742 AMQ601502: User anonymous@invm:0 acknowledged message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: CoreMessage[messageID=35184, durable=true, userID=b41d7331-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:57 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b41cfdfe-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@1224728746, transaction: TransactionImpl [xid=null, txID=35185, xid=null, state=COMMITTED, createTime=1712815617742(Thu Apr 11 07:06:57 BST 2024), timeoutSeconds=-1, nr operations = 0]@735ba633 (AuditLogger_impl.java [Thread-4 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:57,743 AMQ601768: CORE connection b41cafdc-f7c9-11ee-9506-0242ac110003 for user anonymous@invm:0 destroyed (AuditLogger_impl.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,743 AMQ601768: CORE connection b41cafdc-f7c9-11ee-9506-0242ac110003 for user anonymous@invm:0 destroyed (AuditLogger_impl.java [taskScheduler-19])
* WARN  2024-04-11T07:06:57,744 AMQ212037: Connection failure to invm:0 has been detected: null [code=GENERIC_EXCEPTION] (ActiveMQClientLogger_impl.java [taskScheduler-19])
* WARN  2024-04-11T07:06:57,744 AMQ212037: Connection failure to invm:0 has been detected: null [code=GENERIC_EXCEPTION] (ActiveMQClientLogger_impl.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,746 [META_DATA_SYNC jAV3TZn79CG] Stage started: Setting up metadata synchronisation (ControlledJobProgress.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,746 [META_DATA_SYNC jAV3TZn79CG] Stage completed after 0s (ControlledJobProgress.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,747 [META_DATA_SYNC jAV3TZn79CG] Process started: Starting DataValueSynchronization job (ControlledJobProgress.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,909 [META_DATA_SYNC jAV3TZn79CG] Stage started: Counting data values (ControlledJobProgress.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,910 [META_DATA_SYNC jAV3TZn79CG] Stage completed after 0.002s: DataValues last changed before Thu Jan 01 01:00:00 GMT 1970 will not be synchronized. (ControlledJobProgress.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,910 [META_DATA_SYNC jAV3TZn79CG] Process completed after 0.163s: Skipping synchronization, no new or updated DataValues (ControlledJobProgress.java [taskScheduler-19])
* INFO  2024-04-11T07:06:57,910 [META_DATA_SYNC jAV3TZn79CG] Process started: Starting Event programs data synchronization job. (ControlledJobProgress.java [taskScheduler-19])
* INFO  2024-04-11T07:06:58,039 [META_DATA_SYNC jAV3TZn79CG] Stage started: Counting anonymous events ready to be synchronised. (ControlledJobProgress.java [taskScheduler-19])
* WARN  2024-04-11T07:06:58,041 [META_DATA_SYNC jAV3TZn79CG] Process aborted after 0.295s: aborted after error: java.lang.NullPointerException (ControlledJobProgress.java [taskScheduler-19])
* WARN  2024-04-11T07:06:58,041 [META_DATA_SYNC jAV3TZn79CG] Process aborted after 0.131s: aborted after error: java.lang.NullPointerException (ControlledJobProgress.java [taskScheduler-19])
* ERROR 2024-04-11T07:06:58,042 [META_DATA_SYNC jAV3TZn79CG] Stage failed after 0.002s: java.lang.NullPointerException (ControlledJobProgress.java [taskScheduler-19])
java.lang.NullPointerException: null
	at org.hisp.dhis.dxf2.events.event.JdbcEventStore.isUserSearchScopeNotSet(JdbcEventStore.java:1495) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.events.event.JdbcEventStore.createAccessibleSql(JdbcEventStore.java:1405) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.events.event.JdbcEventStore.getOrgUnitSql(JdbcEventStore.java:1386) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.events.event.JdbcEventStore.getFromWhereClause(JdbcEventStore.java:1280) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.events.event.JdbcEventStore.getEventSelectQuery(JdbcEventStore.java:1104) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.events.event.JdbcEventStore.getEventCount(JdbcEventStore.java:856) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.events.event.AbstractEventService.getAnonymousEventReadyForSynchronizationCount(AbstractEventService.java:500) ~[dhis-service-dxf2-2.40.3.jar:?]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.31.jar:5.3.31]
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.31.jar:5.3.31]
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.31.jar:5.3.31]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:241) ~[spring-aop-5.3.31.jar:5.3.31]
	at com.sun.proxy.$Proxy439.getAnonymousEventReadyForSynchronizationCount(Unknown Source) ~[?:?]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:137) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:124) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.31.jar:5.3.31]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:241) ~[spring-aop-5.3.31.jar:5.3.31]
	at com.sun.proxy.$Proxy279.getAnonymousEventReadyForSynchronizationCount(Unknown Source) ~[?:?]
	at org.hisp.dhis.dxf2.sync.EventSynchronization.createContext(EventSynchronization.java:136) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.sync.EventSynchronization.lambda$synchronizeData$1(EventSynchronization.java:112) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.scheduling.JobProgress.runStage(JobProgress.java:413) ~[dhis-api-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.sync.EventSynchronization.synchronizeData(EventSynchronization.java:106) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.metadata.sync.MetadataSyncPreProcessor.handleEventProgramsDataPush(MetadataSyncPreProcessor.java:109) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.metadata.jobs.MetadataSyncJob.runSyncTask(MetadataSyncJob.java:142) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.dxf2.metadata.jobs.MetadataSyncJob.lambda$execute$0(MetadataSyncJob.java:121) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.springframework.retry.support.RetryTemplate.doExecute(RetryTemplate.java:329) ~[spring-retry-1.3.4.jar:?]
	at org.springframework.retry.support.RetryTemplate.execute(RetryTemplate.java:225) ~[spring-retry-1.3.4.jar:?]
	at org.hisp.dhis.dxf2.metadata.jobs.MetadataSyncJob.execute(MetadataSyncJob.java:117) ~[dhis-service-dxf2-2.40.3.jar:?]
	at org.hisp.dhis.scheduling.AbstractSchedulingManager.execute(AbstractSchedulingManager.java:292) ~[dhis-service-core-2.40.3.jar:?]
	at org.hisp.dhis.scheduling.DefaultSchedulingManager.lambda$executeNow$6(DefaultSchedulingManager.java:201) ~[dhis-service-core-2.40.3.jar:?]
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) [spring-context-5.3.31.jar:5.3.31]
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:829) [?:?]
* INFO  2024-04-11T07:06:58,042 [META_DATA_SYNC jAV3TZn79CG] Process completed after 0s: Event programs data synchronization skipped. No new or updated events found. (ControlledJobProgress.java [taskScheduler-19])
* INFO  2024-04-11T07:06:58,047 AMQ601767: CORE connection b44c7273-f7c9-11ee-9506-0242ac110003 for user unknown@invm:0 created (AuditLogger_impl.java [taskScheduler-19])
* INFO  2024-04-11T07:06:58,047 AMQ601767: CORE connection b44c7273-f7c9-11ee-9506-0242ac110003 for user unknown@invm:0 created (AuditLogger_impl.java [taskScheduler-19])
* INFO  2024-04-11T07:06:58,048 AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::name=localhost with parameters: [b44cc096-f7c9-11ee-9506-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=b44c7273-f7c9-11ee-9506-0242ac110003, clientID=null, nodeID=2d644d5d-f7c5-11ee-9506-0242ac110003, transportConnection=InVMConnection [serverID=0, id=b44c7273-f7c9-11ee-9506-0242ac110003]], false, false, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@385536db, true, {}] (AuditLogger_impl.java [Thread-3 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,048 AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::name=localhost with parameters: [b44cc096-f7c9-11ee-9506-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=b44c7273-f7c9-11ee-9506-0242ac110003, clientID=null, nodeID=2d644d5d-f7c5-11ee-9506-0242ac110003, transportConnection=InVMConnection [serverID=0, id=b44c7273-f7c9-11ee-9506-0242ac110003]], false, false, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@385536db, true, {}] (AuditLogger_impl.java [Thread-3 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,050 AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::name=localhost with parameters: [b44d0eb7-f7c9-11ee-9506-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=b44c7273-f7c9-11ee-9506-0242ac110003, clientID=null, nodeID=2d644d5d-f7c5-11ee-9506-0242ac110003, transportConnection=InVMConnection [serverID=0, id=b44c7273-f7c9-11ee-9506-0242ac110003]], true, true, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@645a438c, true, {}] (AuditLogger_impl.java [Thread-8 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,050 AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::name=localhost with parameters: [b44d0eb7-f7c9-11ee-9506-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=b44c7273-f7c9-11ee-9506-0242ac110003, clientID=null, nodeID=2d644d5d-f7c5-11ee-9506-0242ac110003, transportConnection=InVMConnection [serverID=0, id=b44c7273-f7c9-11ee-9506-0242ac110003]], true, true, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@645a438c, true, {}] (AuditLogger_impl.java [Thread-8 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,055 AMQ601500: User anonymous@invm:0 sent a message CoreMessage[messageID=35194, durable=true, userID=b44daaf9-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:58 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b44cc095-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@757897691, context: RoutingContextImpl(Address=dhis2.topic.metadata, routingType=MULTICAST, PreviousAddress=dhis2.topic.metadata previousRoute:MULTICAST, reusable=true, version=-2147483640)
..................................................
***** durable queues dhis2.topic.metadata:
***** non durable for dhis2.topic.metadata:
- queueID=104 address:dhis2.topic.metadata name:24038330-11ef-49a2-ac9f-d35d2464d8dd filter:null
..................................................
, transaction: null (AuditLogger_impl.java [Thread-5 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,055 AMQ601500: User anonymous@invm:0 sent a message CoreMessage[messageID=35194, durable=true, userID=b44daaf9-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:58 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b44cc095-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@757897691, context: RoutingContextImpl(Address=dhis2.topic.metadata, routingType=MULTICAST, PreviousAddress=dhis2.topic.metadata previousRoute:MULTICAST, reusable=true, version=-2147483640)
..................................................
***** durable queues dhis2.topic.metadata:
***** non durable for dhis2.topic.metadata:
- queueID=104 address:dhis2.topic.metadata name:24038330-11ef-49a2-ac9f-d35d2464d8dd filter:null
..................................................
, transaction: null (AuditLogger_impl.java [Thread-5 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,055 AMQ601501: User anonymous@invm:0 is consuming a message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: Reference[35194]:RELIABLE:CoreMessage[messageID=35194, durable=true, userID=b44daaf9-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:58 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b44cc095-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@757897691 (AuditLogger_impl.java [Thread-13 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,055 AMQ601501: User anonymous@invm:0 is consuming a message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: Reference[35194]:RELIABLE:CoreMessage[messageID=35194, durable=true, userID=b44daaf9-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:58 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b44cc095-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@757897691 (AuditLogger_impl.java [Thread-13 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,061 AMQ601759: User anonymous@invm:0 added acknowledgement of a message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: CoreMessage[messageID=35194, durable=true, userID=b44daaf9-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:58 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b44cc095-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@757897691 to transaction: TransactionImpl [xid=null, txID=35195, xid=null, state=ACTIVE, createTime=1712815618061(Thu Apr 11 07:06:58 BST 2024), timeoutSeconds=-1, nr operations = 1]@4c3e9be4 (AuditLogger_impl.java [Thread-12 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,061 AMQ601759: User anonymous@invm:0 added acknowledgement of a message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: CoreMessage[messageID=35194, durable=true, userID=b44daaf9-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:58 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b44cc095-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@757897691 to transaction: TransactionImpl [xid=null, txID=35195, xid=null, state=ACTIVE, createTime=1712815618061(Thu Apr 11 07:06:58 BST 2024), timeoutSeconds=-1, nr operations = 1]@4c3e9be4 (AuditLogger_impl.java [Thread-12 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,061 AMQ601502: User anonymous@invm:0 acknowledged message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: CoreMessage[messageID=35194, durable=true, userID=b44daaf9-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:58 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b44cc095-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@757897691, transaction: TransactionImpl [xid=null, txID=35195, xid=null, state=COMMITTED, createTime=1712815618061(Thu Apr 11 07:06:58 BST 2024), timeoutSeconds=-1, nr operations = 0]@4c3e9be4 (AuditLogger_impl.java [Thread-12 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,061 AMQ601502: User anonymous@invm:0 acknowledged message from 24038330-11ef-49a2-ac9f-d35d2464d8dd: CoreMessage[messageID=35194, durable=true, userID=b44daaf9-f7c9-11ee-9506-0242ac110003, priority=4, timestamp=Thu Apr 11 07:06:58 BST 2024, expiration=0, durable=true, address=dhis2.topic.metadata, size=1736, properties=TypedProperties[__AMQ_CID=b44cc095-f7c9-11ee-9506-0242ac110003, _AMQ_ROUTING_TYPE=0]]@757897691, transaction: TransactionImpl [xid=null, txID=35195, xid=null, state=COMMITTED, createTime=1712815618061(Thu Apr 11 07:06:58 BST 2024), timeoutSeconds=-1, nr operations = 0]@4c3e9be4 (AuditLogger_impl.java [Thread-12 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@2a36807f)])
* INFO  2024-04-11T07:06:58,062 AMQ601768: CORE connection b44c7273-f7c9-11ee-9506-0242ac110003 for user anonymous@invm:0 destroyed (AuditLogger_impl.java [taskScheduler-19])
* INFO  2024-04-11T07:06:58,062 AMQ601768: CORE connection b44c7273-f7c9-11ee-9506-0242ac110003 for user anonymous@invm:0 destroyed (AuditLogger_impl.java [taskScheduler-19])
* WARN  2024-04-11T07:06:58,063 AMQ212037: Connection failure to invm:0 has been detected: null [code=GENERIC_EXCEPTION] (ActiveMQClientLogger_impl.java [taskScheduler-19])
* WARN  2024-04-11T07:06:58,063 AMQ212037: Connection failure to invm:0 has been detected: null [code=GENERIC_EXCEPTION] (ActiveMQClientLogger_impl.java [taskScheduler-19])
6

I think there is misconfiguration issue

1 Like
7

Hi @Gassim
I have tested the MD sync creating two local instances with no data/metadata present. The sync works fine in 2.37 but same setup in 2.40 breaks the sync with same Null Pointer Exception.
I did not perform any db restore in local so here no data/ metadata is responsible for breaking the sync. The sync seems to break in 2.40 upgrade.
DHIS documentation doesn’t specify any extra configurations to be added for the sync in 2.40.3.
Can anything be done about this?

1 Like