ResourceChangeListener strange behaviour

[user08928]

Hello,

I have a simple scenario - a node in the repository that we want to 'observe' and perform some action in case this node changes. ResourceChangeListener (https://sling.apache.org/apidocs/sling9/org/apache/sling/api/resource/observation/ResourceChangeList...) looked very promising, however I ran into couple of problems.

1) Sample component declaration (simplified)

(
        service = ResourceChangeListener.class,
        immediate = true,
        property = {
                ResourceChangeListener.PATHS + "=/apps/globallink-adaptor/config/repositories/blueprint",
                ResourceChangeListener.PATHS + "=/apps/globallink-adaptor/config/repositories/blueprint-xf",
                ResourceChangeListener.CHANGES + "=ADDED",
                ResourceChangeListener.CHANGES + "=CHANGED",
                ResourceChangeListener.CHANGES + "=REMOVED",
        }
)
@ServiceDescription("Custom change listener")
public class CustomListener implements ResourceChangeListener {

 
    public void onChange(List<ResourceChange> changeList) {
        for (ResourceChange resourceChange : changeList){
            LOGGER.info("==> Caught change. Change type: {}, Change target: {}, UserID: {}", resourceChange.getType(), resourceChange.getPath(), resourceChange.getUserId() );
        }
}

2) And now the problems:

- whenever I change the 'observed' node(s) I can see the listeners triggers number of times (between 1 - 4, I haven't found any pattern), visible in the log

2022-07-08 16:38:39.577 INFO [obfuscated] ==> Caught change. Change type: CHANGED, Change target: /apps/globallink-adaptor/config/repositories/blueprint-xf, UserID: admin
2022-07-08 16:38:39.579 INFO [obfuscated] ==> Caught change. Change type: CHANGED, Change target: /apps/globallink-adaptor/config/repositories/blueprint-xf, UserID: admin
2022-07-08 16:38:39.581 INFO [obfuscated] ==> Caught change. Change type: CHANGED, Change target: /apps/globallink-adaptor/config/repositories/blueprint-xf, UserID: admin
2022-07-08 16:38:39.585 INFO [obfuscated] ==> Caught change. Change type: CHANGED, Change target: /apps/globallink-adaptor/config/repositories/blueprint-xf, UserID: admin

 - in my code I'm performing certain operations like getting ResourceResolver from service user, for some of these triggers (all caused by a single change) this seems to fail without any reason in the logs why that would be so

- if I make an update to my code and push changes to local AEM, changes are NOT always propagated into executed code (perhaps some caching?). I can see that for example when I modify the message being logged, AEM keeps on logging as per the original code. Additionally when I'm debugging via remote java app I sometimes get the warning in my IDE that source code does not match the executed code.

When I raised this to the Adobe support I got l was told they did not support customization (yes, very helpful). I was wondering if anyone here has run into similar behaviour?

Thanks!

[Shailesh_Bassi_]

Hi @user08928 Tried out the same on AEM 6.5.12 and for me it is working as designed.

The only difference is I am using the Annotations in a different way. You can try this and check

Code Snippet

import java.util.List;

import org.apache.sling.api.resource.observation.ResourceChange;
import org.apache.sling.api.resource.observation.ResourceChangeListener;
import org.osgi.service.component.annotations.Component;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

@Component(
		immediate = true,
	    service = ResourceChangeListener.class,
	    property = {
	        ResourceChangeListener.PATHS+"="+"/content/mysite/us/en",	        	       
	        ResourceChangeListener.CHANGES+"="+"ADDED",
	        ResourceChangeListener.CHANGES+"="+"REMOVED",
	        ResourceChangeListener.CHANGES+"="+"CHANGED"
	    }
)	     
public class CustomListener implements ResourceChangeListener {

	private final Logger logger = LoggerFactory.getLogger(CustomListener.class);

	@Override
	public void onChange(List<ResourceChange> changeList) {
		logger.info("starting");
		// TODO Auto-generated method stub
		for (ResourceChange resourceChange : changeList){
			logger.info("==> Caught change. Change type: {}, Change target: {}, UserID: {}", resourceChange.getType(), resourceChange.getPath(), resourceChange.getUserId() );
        }
		logger.info("end");
	}
}

[user08928]

The only difference I can see is that you're constructing the key:value pair slightly differently. I have tried both ways and no difference - if I check the service in the OSGi console, the config looks the same (so apparently it probably makes no difference how is the annotation constructed).

Also, the OSGi headers look the same (which is what AEM uses to use as service description in the OSGi console).

<scr:component xmlns:scr="http://www.osgi.org/xmlns/scr/v1.3.0" name="dhl.logistics.tools.tdcblueprintcopy.listeners.TDCConfigUpdateListener" immediate="true">
  <property name="service.description" type="String" value="TDC blueprint change listener"/>
  <property name="resource.change.types" type="String">ADDED
REMOVED
CHANGED</property>
  <property name="resource.paths" type="String">/apps/globallink-adaptor/config/repositories/blueprint
/apps/globallink-adaptor/config/repositories/blueprint-xf</property>

[Aditya_Chabuku]

Hi @user08928 

There are two major problems in your question. 

1.  Your Listner is calling more than once for a simple change.
2. Your IDE code & Code installed in OSGI is different.

Let's see first problem now, Only way a listener is called more than once is its getting multiple requests from same node. This happens when you have any dependencies on that node value.

Try to implement a workflow via Launcher & see if you have same problem there.

Second Problem: Your code in IDE is updated as per you, but when you do 

mvn clean install -PautoInstallPackage

the new jar file will be deployed in OSGI, however since your new jar file & old jar file has same POM versions, sometimes OSGI don't just install new jar. So it's our responsibility to check the installation time on the OSGI console for our bundles.

Please check for the below value every time you install a new jar.

~Aditya.Ch

[user08928]

Thank you for your response. I'm dealing with snapshot versions only (where AEM behaviour is different than with 'release' versions) and this is a behaviour I have not yet observed before (where jar file wouldn't have been updated correctly). It seems to only happen with this particular functionality (it's not the only thing going on in the bundle of course).

It's a good tip to check the bundle installation date though, thanks for that!

[Aditya_Chabuku]

Hi @user08928 ,  did you find out what is happening with that bundle..? Is this thing resolved?

Please let me know what you have done about it.!

[user08928]

Sadly, no. I have spoken to Adobe consultant our project uses, but he wasn't sure either, however he did not think it was an environmental issue.

[aanchal-sikka]

The issue where your changes are not reflecting on deployment, is not specific to listener. I have observed this intermittently with various OSGi services like feature flag.

When in doubt, I duplicate the code as a new service and verify. An AEM restart is mostly able to solve it.

If an AEM restart also doesn't help, may be spin a new instance.