search

tronghuyict56 / openhab

Automatically exported from code.google.com/p/openhab
0 stars 0 forks source link

Item model not loading correctly on RaspberryPi #517

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago 
What steps will reproduce the problem?
1. Configured item model in Windows, works fine
2. copied whole OpenHAB runtime folder to RaspberryPi, started in debug mode, 
creates error "Couldn't find ItemFactory for item '{}' of type '{}'" for all 
items.

What is the expected output? What do you see instead?
-

What version of the product are you using? On what operating system?
- tried 2013-05-25-wheezy-raspbian with java 8 and 2013-09-25-wheezy-raspbian 
with java 7 and 8, OH1.3.1

Please provide any additional information below.
- most interesting log entry is the difference in the logging between windows 
and raspi startup:

First the windows start:
23:11:40.743 INFO  o.o.c.internal.CoreActivator[:92] - openHAB runtime has been 
started (v1.3.1).
23:11:40.760 DEBUG o.o.c.a.i.AutoUpdateActivator[:51] - AutoUpdate binding has 
been started.
23:11:41.231 DEBUG o.o.m.p.i.PersistenceModelActivator[:43] - Registered 
'persistence' configuration parser
23:11:41.242 DEBUG o.o.c.t.i.TransformationActivator[:58] - Transformation 
Service has been started.
23:11:41.369 DEBUG o.o.i.g.internal.GCalActivator[:54] - Google Calendar IO has 
been started.
23:11:41.386 DEBUG o.o.i.m.i.MultimediaActivator[:54] - Multimedia I/O bundle 
has been started.
23:11:41.401 DEBUG o.o.i.s.i.DiscoveryServiceActivator[:47] - Discovery service 
has been started.
23:11:41.412 DEBUG o.o.i.t.mqtt.MqttService[:138] - Starting MQTT Service...
23:11:41.484 DEBUG o.o.m.i.i.ItemModelActivator[:44] - Registered 'item' 
configuration parser
23:11:41.549 DEBUG o.o.c.i.items.ItemRegistryImpl[:157] - Item provider 
'GenericItemProvider' has been added.
23:11:41.962 DEBUG o.o.m.s.i.SitemapModelActivator[:43] - Registered 'sitemap' 
configuration parser
23:11:42.052 INFO  o.o.m.c.i.ModelRepositoryImpl[:99] - Loading model 
'homematic.items'
23:11:42.102 DEBUG o.o.m.i.i.GenericItemProvider[:154] - Read items from model 
'homematic.items'
23:11:42.110 DEBUG o.o.i.r.internal.RESTActivator[:53] - REST API has been 
started.
23:11:42.192 INFO  o.o.i.s.i.DiscoveryServiceImpl[:92] - mDNS service has been 
started

And here the Raspi start:

22:15:54.734 INFO  o.o.c.internal.CoreActivator[:92] - openHAB runtime has been 
started (v1.3.1).
22:15:57.474 DEBUG o.o.c.a.i.AutoUpdateActivator[:51] - AutoUpdate binding has 
been started.
22:16:43.068 DEBUG o.o.m.p.i.PersistenceModelActivator[:43] - Registered 
'persistence' configuration parser
22:16:43.668 DEBUG o.o.c.t.i.TransformationActivator[:58] - Transformation 
Service has been started.
22:16:46.389 DEBUG o.o.i.g.internal.GCalActivator[:54] - Google Calendar IO has 
been started.
22:16:47.960 DEBUG o.o.i.m.i.MultimediaActivator[:54] - Multimedia I/O bundle 
has been started.
22:16:51.405 DEBUG o.o.i.s.i.DiscoveryServiceActivator[:47] - Discovery service 
has been started.
22:16:53.491 DEBUG o.o.i.t.mqtt.MqttService[:138] - Starting MQTT Service...
22:17:02.385 INFO  o.o.m.c.i.ModelRepositoryImpl[:99] - Loading model 
'rrd4j.persist'
22:17:10.237 DEBUG o.o.m.i.i.ItemModelActivator[:44] - Registered 'item' 
configuration parser
22:17:14.642 INFO  o.o.m.c.i.ModelRepositoryImpl[:99] - Loading model 
'homematic.items'
22:17:22.564 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Anwesenheit' of type 'Number'
22:17:22.581 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Wohnmodus' of type 'Number'
22:17:22.601 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Shutter_OG_Eltern' of type 'Rollershutter'
22:17:22.619 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Shutter_OG_Bad' of type 'Rollershutter'
22:17:22.636 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Shutter_OG_Arbeit_Window' of type 'Rollershutter'
22:17:22.652 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Shutter_OG_Arbeit_Door' of type 'Rollershutter'
22:17:22.670 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Wandtaster_FL_PB4_1' of type 'Switch'
22:17:22.688 DEBUG o.o.m.i.i.GenericItemProvider[:312] - Start processing 
binding configuration of Item 'null' with 'AutoUpdateGenericBindingProvider' 
reader.
22:17:25.360 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Anwesenheit' of type 'Number'
22:17:25.377 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Wohnmodus' of type 'Number'
22:17:25.395 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Shutter_OG_Eltern' of type 'Rollershutter'
22:17:25.415 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Shutter_OG_Bad' of type 'Rollershutter'
22:17:25.432 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Shutter_OG_Arbeit_Window' of type 'Rollershutter'
22:17:25.449 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Shutter_OG_Arbeit_Door' of type 'Rollershutter'
22:17:25.466 DEBUG o.o.m.i.i.GenericItemProvider[:382] - Couldn't find 
ItemFactory for item 'Wandtaster_FL_PB4_1' of type 'Switch'
22:17:26.238 DEBUG o.o.m.i.i.GenericItemProvider[:154] - Read items from model 
'homematic.items'
22:18:16.843 DEBUG o.o.m.s.i.SitemapModelActivator[:43] - Registered 'sitemap' 
configuration parser
22:18:20.938 DEBUG o.o.i.r.internal.RESTActivator[:53] - REST API has been 
started.
22:18:23.004 INFO  o.o.i.s.i.DiscoveryServiceImpl[:92] - mDNS service has been 
started

The main difference (apart from the ages it take for the Raspi to start) is 
that the line

22:04:35.185 DEBUG o.o.c.i.items.ItemRegistryImpl[:157] - Item provider 
'GenericItemProvider' has been added.

is coming before loading of the model in windows and it is missing (once it 
cames after loading the model) on the Raspi. That doesn't seem to make sense. I 
took a glance in the code but didn'd dig deep enough.

Original issue reported on code.google.com by yannick....@gmail.com on 15 Nov 2013 at 10:31

GoogleCodeExporter commented 8 years ago 
I assume this is a startlevel problem. I have just committed a fix to start the 
itemtype factory earlier than the rest: 
https://github.com/openhab/openhab/commit/b8d5feb1d771c7c350efa68ee7240864299a5f
4c

Please test it with tomorrows build and let me know if it solves the problem!

Original comment by kai.openhab on 15 Nov 2013 at 11:03

GoogleCodeExporter commented 8 years ago 
Thx for the quick reaction Kai, but that's still open. There are less errors 
now because I reduced the model to just one item.

I used #527 from today. "GenericItemProvider" is still loading after the model 
(although reading of the model now appears twice):

09:29:28.618 INFO  o.q.impl.StdSchedulerFactory[:1328] - Quartz scheduler 
version: 2.1.7
09:29:28.641 INFO  o.quartz.core.QuartzScheduler[:534] - Scheduler 
openHAB-job-scheduler_$_NON_CLUSTERED started.
09:29:28.766 DEBUG o.o.c.core.ConfigDispatcher[:146] - Processing openHAB 
default configuration file 
'/home/pi/distribution-1.4.0-SNAPSHOT-runtime/configurations/openhab_default.cfg
'.
09:29:30.820 DEBUG o.o.c.core.ConfigDispatcher[:168] - Processing openHAB main 
configuration file 
'/home/pi/distribution-1.4.0-SNAPSHOT-runtime/configurations/openhab.cfg'.
09:29:32.272 DEBUG o.o.c.internal.CoreActivator[:104] - UUID file already 
exists at '/home/pi/distribution-1.4.0-SNAPSHOT-runtime/webapps/static/uuid' 
with content '4eec0a46-23fc-4d00-9e41-6de4393ec35d'
09:29:37.113 DEBUG o.o.c.internal.CoreActivator[:170] - You are running 
'v1.4.0' a potentially unstable version of openHAB. The current stable version 
is 'v1.3.1'.
09:29:37.147 DEBUG o.o.c.internal.CoreActivator[:126] - Created file 
'/home/pi/distribution-1.4.0-SNAPSHOT-runtime/webapps/static/version' with 
content '1.4.0'
09:29:37.164 INFO  o.o.c.internal.CoreActivator[:72] - openHAB runtime has been 
started (v1.4.0).
09:29:38.661 DEBUG o.o.c.a.i.AutoUpdateActivator[:31] - AutoUpdate binding has 
been started.
09:30:24.112 DEBUG o.o.m.p.i.PersistenceModelActivator[:23] - Registered 
'persistence' configuration parser
09:30:24.819 DEBUG o.o.c.t.i.TransformationActivator[:38] - Transformation 
Service has been started.
09:30:27.356 DEBUG o.o.i.g.internal.GCalActivator[:34] - Google Calendar IO has 
been started.
09:30:28.697 DEBUG o.o.i.m.i.MultimediaActivator[:34] - Multimedia I/O bundle 
has been started.
09:30:31.277 DEBUG o.o.i.s.i.DiscoveryServiceActivator[:27] - Discovery service 
has been started.
09:30:32.129 DEBUG o.o.i.t.mqtt.MqttService[:118] - Starting MQTT Service...
09:30:42.089 INFO  o.o.m.c.i.ModelRepositoryImpl[:79] - Loading model 
'rrd4j.persist'
09:30:49.266 DEBUG o.o.m.i.i.ItemModelActivator[:24] - Registered 'item' 
configuration parser
09:30:53.184 INFO  o.o.m.c.i.ModelRepositoryImpl[:79] - Loading model 
'homematic.items'
09:31:01.309 DEBUG o.o.m.i.i.GenericItemProvider[:408] - Couldn't find 
ItemFactory for item 'Wandtaster_FL_PB4_1' of type 'Switch'
09:31:01.328 DEBUG o.o.m.i.i.GenericItemProvider[:334] - Start processing 
binding configuration of Item 'null' with 'AutoUpdateGenericBindingProvider' 
reader.
09:31:05.201 DEBUG o.o.m.i.i.GenericItemProvider[:133] - Read items from model 
'homematic.items'
09:31:05.328 DEBUG o.o.c.i.items.ItemRegistryImpl[:137] - Item provider 
'GenericItemProvider' has been added.
09:31:05.352 DEBUG o.o.m.i.i.GenericItemProvider[:133] - Read items from model 
'homematic.items'
09:31:54.816 DEBUG o.o.m.s.i.SitemapModelActivator[:23] - Registered 'sitemap' 
configuration parser
09:31:59.464 DEBUG o.o.i.r.internal.RESTActivator[:33] - REST API has been 
started.
09:32:01.600 INFO  o.o.i.s.i.DiscoveryServiceImpl[:72] - mDNS service has been 
started
09:32:06.291 INFO  o.o.m.c.i.ModelRepositoryImpl[:79] - Loading model 
'default.sitemap'
09:32:10.024 INFO  o.a.cpr.AtmosphereFramework[:2154] - Atmosphere is using 
org.atmosphere.cpr.DefaultAnnotationProcessor for processing annotation
09:32:10.115 INFO  o.a.c.DefaultAnnotationProcessor[:131] - AnnotationProcessor 
class 
org.atmosphere.cpr.DefaultAnnotationProcessor$BytecodeBasedAnnotationProcessor 
being used
09:32:13.468 INFO  o.a.cpr.AtmosphereFramework[:1491] - Auto detecting 
atmosphere handlers /WEB-INF/classes/

Original comment by yannick....@gmail.com on 16 Nov 2013 at 9:40

GoogleCodeExporter commented 8 years ago 
Hm, pity that it didn't solve it. :-(
Will have to do testing myself then on a RaspPi to really fix the issue. Hope I 
will find time for it soon.

Original comment by kai.openhab on 16 Nov 2013 at 10:20

GoogleCodeExporter commented 8 years ago

Original comment by kai.openhab on 16 Nov 2013 at 10:20

GoogleCodeExporter commented 8 years ago 
[deleted comment]
GoogleCodeExporter commented 8 years ago 
This issue has been migrated to Github. If this issue id is greater than103 its 
id has been preserved on Github. You can open your issue by calling the URL 
https://github.com/openhab/openhab/issues/<issueid>. Issues with ids less or 
equal 103 new ids were created.

Original comment by teichsta on 17 Nov 2013 at 8:09

GoogleCodeExporter commented 8 years ago 
Set status to "invalid" to show that these issues are not tracked here anymore 
- please refer to GitHub instead!

Original comment by kai.openhab on 2 Dec 2013 at 7:12