{"action":"closed","issue":{"url":"https://api.github.com/repos/eclipse/smarthome/issues/2830","repository_url":"https://api.github.com/repos/eclipse/smarthome","labels_url":"https://api.github.com/repos/eclipse/smarthome/issues/2830/labels{/name}","comments_url":"https://api.github.com/repos/eclipse/smarthome/issues/2830/comments","events_url":"https://api.github.com/repos/eclipse/smarthome/issues/2830/events","html_url":"https://github.com/eclipse/smarthome/issues/2830","id":200892896,"number":2830,"title":"Phantom items appear after exception while saving items and things","user":{"login":"jackdewinter","id":25124582,"avatar_url":"https://avatars1.githubusercontent.com/u/25124582?v=4","gravatar_id":"","url":"https://api.github.com/users/jackdewinter","html_url":"https://github.com/jackdewinter","followers_url":"https://api.github.com/users/jackdewinter/followers","following_url":"https://api.github.com/users/jackdewinter/following{/other_user}","gists_url":"https://api.github.com/users/jackdewinter/gists{/gist_id}","starred_url":"https://api.github.com/users/jackdewinter/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jackdewinter/subscriptions","organizations_url":"https://api.github.com/users/jackdewinter/orgs","repos_url":"https://api.github.com/users/jackdewinter/repos","events_url":"https://api.github.com/users/jackdewinter/events{/privacy}","received_events_url":"https://api.github.com/users/jackdewinter/received_events","type":"User","site_admin":false},"labels":[],"state":"closed","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":4,"created_at":"2017-01-15T20:41:14Z","updated_at":"2017-08-28T11:47:17Z","closed_at":"2017-08-28T11:47:17Z","body":"Log file below.  I am not 100% sure, but after that error happens is when this seems to occur.  \r\n\r\nI am not sure how I got into this state, but once there, I see logs like:\r\n```\r\n12:20:21.269 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update 'on' for item 'Office_DeskBackLight_Status' to handler for channel 'exec:command:office_deskbacklight_check:output', because no thing with the UID 'exec:command:office_deskbacklight_check' could be found.\r\n12:20:36.602 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update 'on' for item 'Office_DeskBackLight_Status' to handler for channel 'exec:command:office_deskbacklight_check:output', because no thing with the UID 'exec:command:office_deskbacklight_check' could be found.\r\n12:20:51.902 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update 'on' for item 'Office_DeskBackLight_Status' to handler for channel 'exec:command:office_deskbacklight_check:output', because no thing with the UID 'exec:command:office_deskbacklight_check' could be found.\r\n12:20:55.336 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update '0' for item 'Office_DeskBackLight_Ping_Exit' to handler for channel 'exec:command:office_deskbacklight_ping:exit', because no thing with the UID 'exec:command:office_deskbacklight_ping' could be found.\r\n12:20:55.338 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update '{\"sent\":5,\"replies\":5,\"state\":\"online\"}' for item 'Office_DeskBackLight_Ping_Out' to handler for channel 'exec:command:office_deskbacklight_ping:output',because no thing with the UID 'exec:command:office_deskbacklight_ping' could be found.\r\n12:20:55.340 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update '2017-01-15T12:20:55.336-0800' for item 'Office_DeskBackLight_Ping_Last' to handler for channel 'exec:command:office_deskbacklight_ping:lastexecution', because no thing with the UID 'exec:command:office_deskbacklight_ping' could be found.\r\n```\r\nThis was from development, and may have been caused by other bugs I reported.  The important things are \"exec:command:office_deskbacklight_check\" and \"exec:command:office_deskbacklight_ping\".  In both cases, these were named differently, and were things that were refreshing every 15 and 60 seconds.  At those intervals, messages like the above are injected into the log files.\r\n\r\nPicking the check one, I created a thing with the name from the UID:\r\n```\r\nexec:command:office_deskbacklight_check \t\t\t\t\t\t\t\"dead\"\t\t\t\t[command=\"/.../tplink.exe check\", interval=60, timeout=10, transform=\"REGEX(.*stateX\\\":\\\"(.*)\\\".*)\", autorun=false]\r\n```\r\nAt this point, the message turns to:\r\n```\r\n12:30:51.163 [INFO ] [ome.core.thing.internal.ThingManager] - Not delegating update 'on' for item 'Office_DeskBackLight_Status' to handler for channel 'exec:command:office_deskbacklight_check:output', because handler is not initialized (thing must be in status UNKNOWN, ONLINE or OFFLINE).\r\n```\r\nTrying various things at this point, the only one that seems to work is:\r\n1) Change the name of an item to the one it complains about:\r\n2) save the file and observe this in the file:\r\n```\r\n12:37:37.443 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'jack.items'\r\n12:37:37.451 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'Office_DeskBackLight_Status' has been added.\r\n12:37:37.452 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'Office_DeskBackLight_Status-exec:command:office_desk_backlight_check:output' has been added.\r\n12:37:37.458 [INFO ] [smarthome.event.ItemRemovedEvent    ] - Item 'Office_DeskBackLight_Status' has been removed.\r\n12:37:37.464 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'jack.items'\r\n```\r\nIn the cases where that exception occurred, this pattern off added and removed was not present.\r\n\r\n```\r\n12:18:32.995 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model '\r\njack.things'\r\n12:18:33.021 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'ntp:ntp:dem\r\no' has been removed.\r\n12:18:33.025 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'yahooweathe\r\nr:weather:duvall' has been removed.\r\n12:18:33.034 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'astro:sun:h\r\nome' has been removed.\r\n12:18:33.037 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'astro:moon:\r\nhome' has been removed.\r\n12:18:33.044 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'exec:comman\r\nd:officedeskbacklight' has been removed.\r\n12:18:33.048 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'exec:comman\r\nd:officedeskbacklightcheck' has been removed.\r\n12:18:33.051 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'exec:comman\r\nd:officedeskbacklightping' has been removed.\r\n12:18:33.053 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'exec:comman\r\nd:yedead' has been removed.\r\n12:18:33.058 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'exec:command:offi\r\nce_deskbacklight_ping' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERR\r\nOR)\r\n12:18:33.059 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'exec:comman\r\nd:office_deskbacklight_ping' has been removed.\r\n12:18:33.082 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'exec:command:dead\r\n' changed from UNINITIALIZED to INITIALIZING\r\n12:18:33.084 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'exec:command:dead\r\n' changed from INITIALIZING to ONLINE\r\n12:18:33.085 [ERROR] [ore.thing.internal.ThingRegistryImpl] - Could not inform t\r\nhe ThingTracker 'org.eclipse.smarthome.core.thing.internal.ThingManager@13ad5b2'\r\n about the 'THING_UPDATED' event!\r\njava.lang.NullPointerException\r\n        at org.eclipse.smarthome.core.thing.internal.ThingManager.thingUpdated(T\r\nhingManager.java:542)[105:org.eclipse.smarthome.core.thing:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyTra\r\nckers(ThingRegistryImpl.java:227)[105:org.eclipse.smarthome.core.thing:0.9.0.201\r\n701140927]\r\n        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyLis\r\ntenersAboutUpdatedElement(ThingRegistryImpl.java:150)[105:org.eclipse.smarthome.\r\ncore.thing:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyLis\r\ntenersAboutUpdatedElement(ThingRegistryImpl.java:1)[105:org.eclipse.smarthome.co\r\nre.thing:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.core.common.registry.AbstractRegistry.updated(A\r\nbstractRegistry.java:167)[98:org.eclipse.smarthome.core:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyLis\r\nteners(AbstractProvider.java:57)[98:org.eclipse.smarthome.core:0.9.0.20170114092\r\n7]\r\n        at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyLis\r\ntenersAboutUpdatedElement(AbstractProvider.java:82)[98:org.eclipse.smarthome.cor\r\ne:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.acces\r\ns$4(GenericThingProvider.java:1)[133:org.eclipse.smarthome.model.thing:0.9.0.201\r\n701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$21.ap\r\nply(GenericThingProvider.java:1044)[133:org.eclipse.smarthome.model.thing:0.9.0.\r\n201701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$21.ap\r\nply(GenericThingProvider.java:1)[133:org.eclipse.smarthome.model.thing:0.9.0.201\r\n701140927]\r\n        at org.eclipse.xtext.xbase.lib.IteratorExtensions.forEach(IteratorExtens\r\nions.java:363)[146:org.eclipse.xtext.xbase.lib:2.9.2]\r\n        at org.eclipse.xtext.xbase.lib.IterableExtensions.forEach(IterableExtens\r\nions.java:333)[146:org.eclipse.xtext.xbase.lib:2.9.2]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.creat\r\neThingsFromModelForThingHandlerFactory(GenericThingProvider.java:1054)[133:org.e\r\nclipse.smarthome.model.thing:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.acces\r\ns$1(GenericThingProvider.java:1008)[133:org.eclipse.smarthome.model.thing:0.9.0.\r\n201701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$1$1.a\r\npply(GenericThingProvider.java:236)[133:org.eclipse.smarthome.model.thing:0.9.0.\r\n201701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$1$1.a\r\npply(GenericThingProvider.java:1)[133:org.eclipse.smarthome.model.thing:0.9.0.20\r\n1701140927]\r\n        at org.eclipse.xtext.xbase.lib.IteratorExtensions.forEach(IteratorExtens\r\nions.java:363)[146:org.eclipse.xtext.xbase.lib:2.9.2]\r\n        at org.eclipse.xtext.xbase.lib.IterableExtensions.forEach(IterableExtens\r\nions.java:333)[146:org.eclipse.xtext.xbase.lib:2.9.2]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$1.app\r\nly(GenericThingProvider.java:239)[133:org.eclipse.smarthome.model.thing:0.9.0.20\r\n1701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$1.app\r\nly(GenericThingProvider.java:1)[133:org.eclipse.smarthome.model.thing:0.9.0.2017\r\n01140927]\r\n        at org.eclipse.smarthome.config.core.BundleProcessorVetoManager.applyAct\r\nionFor(BundleProcessorVetoManager.java:121)[94:org.eclipse.smarthome.config.core\r\n:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$6.app\r\nly(GenericThingProvider.java:320)[133:org.eclipse.smarthome.model.thing:0.9.0.20\r\n1701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$6.app\r\nly(GenericThingProvider.java:1)[133:org.eclipse.smarthome.model.thing:0.9.0.2017\r\n01140927]\r\n        at org.eclipse.xtext.xbase.lib.IteratorExtensions.forEach(IteratorExtens\r\nions.java:363)[146:org.eclipse.xtext.xbase.lib:2.9.2]\r\n        at org.eclipse.xtext.xbase.lib.IterableExtensions.forEach(IterableExtens\r\nions.java:333)[146:org.eclipse.xtext.xbase.lib:2.9.2]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.creat\r\neThingsFromModel(GenericThingProvider.java:323)[133:org.eclipse.smarthome.model.\r\nthing:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.model\r\nChanged(GenericThingProvider.java:901)[133:org.eclipse.smarthome.model.thing:0.9\r\n.0.201701140927]\r\n        at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.notifyL\r\nisteners(ModelRepositoryImpl.java:207)[122:org.eclipse.smarthome.model.core:0.9.\r\n0.201701140927]\r\n        at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.addOrRe\r\nfreshModel(ModelRepositoryImpl.java:120)[122:org.eclipse.smarthome.model.core:0.\r\n9.0.201701140927]\r\n        at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.check\r\nFile(FolderObserver.java:270)[122:org.eclipse.smarthome.model.core:0.9.0.2017011\r\n40927]\r\n        at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.acces\r\ns$1(FolderObserver.java:264)[122:org.eclipse.smarthome.model.core:0.9.0.20170114\r\n0927]\r\n        at org.eclipse.smarthome.model.core.internal.folder.FolderObserver$Watch\r\nQueueReader.processWatchEvent(FolderObserver.java:145)[122:org.eclipse.smarthome\r\n.model.core:0.9.0.201701140927]\r\n        at org.eclipse.smarthome.core.service.AbstractWatchQueueReader.run(Abstr\r\nactWatchQueueReader.java:122)[98:org.eclipse.smarthome.core:0.9.0.201701140927]\r\n        at java.lang.Thread.run(Thread.java:745)[:1.8.0_111]\r\n```"}}
{"actor":{"display_login":"kaikreuzer"}}