Skip to content
This repository has been archived by the owner on May 7, 2020. It is now read-only.

deactivated XmlBindingInfoProvider is used sometimes #5616

Closed
maggu2810 opened this issue May 23, 2018 · 0 comments
Closed

deactivated XmlBindingInfoProvider is used sometimes #5616

maggu2810 opened this issue May 23, 2018 · 0 comments

Comments

@maggu2810
Copy link
Contributor

maggu2810 commented May 23, 2018 •
edited
Loading

Sometimes I see the following message (just need to restart the container a few times):

The XML document '/ESH-INF/binding/binding.xml' in module 'org.eclipse.smarthome.binding....' could not be parsed: The XmlConfigDescriptionProvider must not be null!

The binding itself does not care.

Here a full stacktrace (line numbers of XmlBindingInfoProvider are changed because I already added some logging info as this stacktrace has been generated):

23:40:54.705 WARN [ESH-file-processing-5] The XML document '/ESH-INF/binding/binding.xml' in module 'org.eclipse.smarthome.binding.bosesoundtouch' could not be parsed: The XmlConfigDescriptionProvider must not be null!
java.lang.IllegalArgumentException: The XmlConfigDescriptionProvider must not be null!
        at org.eclipse.smarthome.core.binding.xml.internal.BindingInfoXmlProvider.<init>(BindingInfoXmlProvider.java:59) ~[?:?]
        at org.eclipse.smarthome.core.binding.xml.internal.XmlBindingInfoProvider.createDocumentProvider(XmlBindingInfoProvider.java:152) ~[?:?]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.acquireXmlDocumentProvider(XmlDocumentBundleTracker.java:174) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.addingObject(XmlDocumentBundleTracker.java:199) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.parseDocuments(XmlDocumentBundleTracker.java:343) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.processBundle(XmlDocumentBundleTracker.java:329) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.access$3(XmlDocumentBundleTracker.java:324) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$2.run(XmlDocumentBundleTracker.java:300) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

As method createDocumentProvider of the XmlBindingInfoProvider is using a mandatory reference for the XmlConfigDescriptionProvider on calling the constructor of BindingInfoXmlProvider.
So. this already leads to the guess that a no more active component is used.

I added some logging to the activate, deactivate, set and unset config description provider and the createDocumentProvider methods.

The logging statement contains System.identityHashCode(this) so it is possible to identify which instance is been used.

Here a reduced log:

23:40:53.785 INFO [FelixStartLevel] XmlBindingInfoProvider - 1605966134: setConfigDescriptionProvider(org.eclipse.smarthome.core.binding.xml.internal.BindingXmlConfigDescriptionProvider@3ff7e9ba)
23:40:53.787 INFO [FelixStartLevel] XmlBindingInfoProvider - 1605966134: activate
23:40:53.794 INFO [FelixStartLevel] XmlBindingInfoProvider - 1605966134: deactivate
23:40:53.804 INFO [FelixStartLevel] XmlBindingInfoProvider - 1605966134: unsetConfigDescriptionProvider(org.eclipse.smarthome.core.binding.xml.internal.BindingXmlConfigDescriptionProvider@3ff7e9ba)
23:40:53.807 INFO [FelixStartLevel] XmlBindingInfoProvider - 607119587: setConfigDescriptionProvider(org.eclipse.smarthome.core.binding.xml.internal.BindingXmlConfigDescriptionProvider@3ff7e9ba)
23:40:53.809 INFO [FelixStartLevel] XmlBindingInfoProvider - 607119587: activate

23:40:54.701 INFO [ESH-file-processing-5] XmlBindingInfoProvider - 1605966134: createDocumentProvider
23:40:54.705 WARN [ESH-file-processing-5] The XML document '/ESH-INF/binding/binding.xml' in module 'org.eclipse.smarthome.binding.bosesoundtouch' could not be parsed: The XmlConfigDescriptionProvider must not be null!
java.lang.IllegalArgumentException: The XmlConfigDescriptionProvider must not be null!
        at org.eclipse.smarthome.core.binding.xml.internal.BindingInfoXmlProvider.<init>(BindingInfoXmlProvider.java:59) ~[?:?]
        at org.eclipse.smarthome.core.binding.xml.internal.XmlBindingInfoProvider.createDocumentProvider(XmlBindingInfoProvider.java:152) ~[?:?]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.acquireXmlDocumentProvider(XmlDocumentBundleTracker.java:174) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.addingObject(XmlDocumentBundleTracker.java:199) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.parseDocuments(XmlDocumentBundleTracker.java:343) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.processBundle(XmlDocumentBundleTracker.java:329) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.access$3(XmlDocumentBundleTracker.java:324) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$2.run(XmlDocumentBundleTracker.java:300) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
23:40:54.704 INFO [ESH-file-processing-4] XmlBindingInfoProvider - 607119587: createDocumentProvider
23:40:54.835 INFO [ESH-file-processing-2] XmlBindingInfoProvider - 607119587: createDocumentProvider
23:40:54.835 INFO [ESH-file-processing-1] XmlBindingInfoProvider - 1605966134: createDocumentProvider
23:40:54.841 WARN [ESH-file-processing-1] The XML document '/ESH-INF/binding/binding.xml' in module 'org.eclipse.smarthome.binding.astro' could not be parsed: The XmlConfigDescriptionProvider must not be null!
java.lang.IllegalArgumentException: The XmlConfigDescriptionProvider must not be null!
        at org.eclipse.smarthome.core.binding.xml.internal.BindingInfoXmlProvider.<init>(BindingInfoXmlProvider.java:59) ~[?:?]
        at org.eclipse.smarthome.core.binding.xml.internal.XmlBindingInfoProvider.createDocumentProvider(XmlBindingInfoProvider.java:152) ~[?:?]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.acquireXmlDocumentProvider(XmlDocumentBundleTracker.java:174) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.addingObject(XmlDocumentBundleTracker.java:199) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.parseDocuments(XmlDocumentBundleTracker.java:343) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.processBundle(XmlDocumentBundleTracker.java:329) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.access$3(XmlDocumentBundleTracker.java:324) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$2.run(XmlDocumentBundleTracker.java:300) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
23:40:54.847 INFO [ESH-file-processing-5] XmlBindingInfoProvider - 1605966134: createDocumentProvider
23:40:54.847 INFO [ESH-file-processing-4] XmlBindingInfoProvider - 607119587: createDocumentProvider
23:40:54.848 WARN [ESH-file-processing-5] The XML document '/ESH-INF/binding/binding.xml' in module 'org.eclipse.smarthome.binding.yahooweather' could not be parsed: The XmlConfigDescriptionProvider must not be null!
java.lang.IllegalArgumentException: The XmlConfigDescriptionProvider must not be null!
        at org.eclipse.smarthome.core.binding.xml.internal.BindingInfoXmlProvider.<init>(BindingInfoXmlProvider.java:59) ~[?:?]
        at org.eclipse.smarthome.core.binding.xml.internal.XmlBindingInfoProvider.createDocumentProvider(XmlBindingInfoProvider.java:152) ~[?:?]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.acquireXmlDocumentProvider(XmlDocumentBundleTracker.java:174) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.addingObject(XmlDocumentBundleTracker.java:199) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.parseDocuments(XmlDocumentBundleTracker.java:343) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.processBundle(XmlDocumentBundleTracker.java:329) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.access$3(XmlDocumentBundleTracker.java:324) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$2.run(XmlDocumentBundleTracker.java:300) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
23:40:54.878 INFO [ESH-file-processing-1] XmlBindingInfoProvider - 1605966134: createDocumentProvider
23:40:54.878 INFO [ESH-file-processing-4] XmlBindingInfoProvider - 607119587: createDocumentProvider
23:40:54.879 WARN [ESH-file-processing-1] The XML document '/ESH-INF/binding/binding.xml' in module 'org.eclipse.smarthome.binding.wemo' could not be parsed: The XmlConfigDescriptionProvider must not be null!
java.lang.IllegalArgumentException: The XmlConfigDescriptionProvider must not be null!
        at org.eclipse.smarthome.core.binding.xml.internal.BindingInfoXmlProvider.<init>(BindingInfoXmlProvider.java:59) ~[?:?]
        at org.eclipse.smarthome.core.binding.xml.internal.XmlBindingInfoProvider.createDocumentProvider(XmlBindingInfoProvider.java:152) ~[?:?]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.acquireXmlDocumentProvider(XmlDocumentBundleTracker.java:174) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.addingObject(XmlDocumentBundleTracker.java:199) ~[110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.parseDocuments(XmlDocumentBundleTracker.java:343) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.processBundle(XmlDocumentBundleTracker.java:329) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.access$3(XmlDocumentBundleTracker.java:324) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$2.run(XmlDocumentBundleTracker.java:300) [110:org.eclipse.smarthome.config.xml:0.10.0.201805232047]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

There is a component instance created 1605966134 and it is deactivate immediately again.
After that another component instance is created 607119587.
The component 607119587 is the only active XmlBindingInfoProvider.

The log shows that createDocumentProvider is called multiple times for the deactivated component 1605966134.

I don't think we should use the component after deactivation anymore.
@maggu2810 maggu2810 mentioned this issue May 23, 2018
Merged
sjsf pushed a commit that referenced this issue May 24, 2018
@maggu2810
xml document bundle tracker: execute submitted task only if opened (#…
77dbd0e 
…5617)

Fixes: #5616
Signed-off-by: Markus Rathgeb <maggu2810@gmail.com>
ermartens pushed a commit to ermartens/smarthome that referenced this issue Jun 15, 2018
@maggu2810
xml document bundle tracker: execute submitted task only if opened (e…
7938b68 
…clipse-archived#5617)

Fixes: eclipse-archived#5616
Signed-off-by: Markus Rathgeb <maggu2810@gmail.com>
@wborn wborn mentioned this issue Sep 13, 2018
Merged
@mhilbush mhilbush mentioned this issue Nov 18, 2018
Closed
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@maggu2810