Add-on dev: itemAdded called multiple times on RegistryChangeListener at boot

Hi there,

I’m maintaining the ImperiHome IO add-on and have an issue getting the item event listener stable when loaded at boot time of openHAB.

Consider the following code:

public class TestAddon {
        
    private final Logger logger = LoggerFactory.getLogger(TestAddon.class);

    private ItemRegistry itemRegistry;

    private ItemProcessor itemProcessor;

    protected void activate() {
        logger.info("TEST - Addon activated");
        itemProcessor = new ItemProcessor(itemRegistry);
    }

    protected void deactivate() {
        itemProcessor.destroy();
        itemProcessor = null;

        logger.info("TEST - Addon deactivated");
    }

    protected void setItemRegistry(ItemRegistry itemRegistry) {
        this.itemRegistry = itemRegistry;
    }

    protected void unsetItemRegistry(ItemRegistry itemRegistry) {
        this.itemRegistry = null;
    }

}



public class ItemProcessor implements ItemRegistryChangeListener {

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

    private final ItemRegistry itemRegistry;

    public ItemProcessor(ItemRegistry itemRegistry) {
        this.itemRegistry = itemRegistry;

        itemRegistry.addRegistryChangeListener(this);
        allItemsChanged(null);
    }

    public void destroy() {
        itemRegistry.removeRegistryChangeListener(this);
    }

    @Override
    public void added(Item item) {
        logger.info("TEST -- Item added: {}", logString(item));
    }

    @Override
    public void removed(Item item) {
        logger.info("TEST -- Item removed: {}", logString(item));
    }

    @Override
    public void updated(Item oldItem, Item newItem) {
        logger.info("TEST -- Item updated, old={} new={}", logString(oldItem), logString(newItem));
    }

    @Override
    public void allItemsChanged(Collection<String> oldItems) {
        logger.info("TEST -- allItemsChanged");

        for (Item item : itemRegistry.getItems()) {
            logger.info("TEST -- allItemsChanged item: {}", logString(item));
        }
    }

    private String logString(Item item) {
        return item.getName() + '@' + Integer.toHexString(System.identityHashCode(item));
    }

}

When dropped into the ‘addons’ directory, this gives me the following log when freshly starting openHAB:

2017-03-10 21:03:19.818 [INFO ] [org.openhab.io.test.ItemProcessor   ] - TEST -- allItemsChanged
2017-03-10 21:03:27.174 [INFO ] [org.openhab.io.test.ItemProcessor   ] - TEST -- Item added: M_ENT_Temperature@3ac4d37c
2017-03-10 21:03:27.388 [INFO ] [org.openhab.io.test.ItemProcessor   ] - TEST -- Item added: M_ENT_Temperature@328f69c5
2017-03-10 21:03:27.659 [INFO ] [org.openhab.io.test.ItemProcessor   ] - TEST -- Item added: M_ENT_Temperature@10aacbc9
2017-03-10 21:03:27.882 [INFO ] [org.openhab.io.test.ItemProcessor   ] - TEST -- Item added: M_ENT_Temperature@12f9dd16
2017-03-10 21:03:28.148 [INFO ] [org.openhab.io.test.ItemProcessor   ] - TEST -- Item added: M_ENT_Temperature@61bd4d5

The ‘added’ method of the ItemProcessor is called 5 times for the same item, but with a different org.eclipse.smarthome.core.items.Item instance. There are no calls to ‘removed’ or ‘updated’ (as expected).
The log is filtered for one particular item; the same happens for all items in my system.

My real add-on is adding a StateChangeListener to each item it’s interested in. However, only the first Item instance provided to ‘added’ is really working and delivering state updates.
This doesn’t seem very stable or desirable. How should my add-on deal with this? Should I ignore repeated ‘added’ calls for the same item name? Is this a bug?

I’m using the current snapshot of openHAB 2. My items are in .items files, so not added with Paper UI.

Thanks in advance,
Pepijn

Nobody?

@Kai Maybe you can point me in the right direction?

Without diving into the code to deeper analyze it, it sounds like a bug to me.
Probably best to open an issue at https://github.com/eclipse/smarthome/issues about it - thanks!