root@scientist-Latitude-D630:/home/scientist/dss-1.3.0/build# ./dss -D ../data -w ../data/webroot -c ../data -p ../data --prop /config/jslogdirectory=../data/logs [2011-11-28 15:19:53][Info][System] Setting property '/config/jslogdirectory' to '../data/logs' [2011-11-28 15:19:53][Info][System] Setting property '/config/datadirectory' to '../data' [2011-11-28 15:19:53][Info][System] Setting property '/config/webrootdirectory' to '../data/webroot' [2011-11-28 15:19:53][Info][System] Setting property '/config/configdirectory' to '../data' [2011-11-28 15:19:53][Info][System] Setting property '/config/savedpropsdirectory' to '../data' [2011-11-28 15:19:53][Info][System] Loading config file ../data/config.xml [2011-11-28 15:19:53][Info][System] Loading config directory ../data/config.d [2011-11-28 15:19:53][Info][System] Setting property '/config/jslogdirectory' to '../data/logs' [2011-11-28 15:19:53][Info][System] Setting property '/config/datadirectory' to '../data' [2011-11-28 15:19:53][Info][System] Setting property '/config/webrootdirectory' to '../data/webroot' [2011-11-28 15:19:53][Info][System] Setting property '/config/configdirectory' to '../data' [2011-11-28 15:19:53][Info][System] Setting property '/config/savedpropsdirectory' to '../data' [2011-11-28 15:19:53][Info][System] No logfile configured, logging to stdout [2011-11-28 15:19:53][Info][System] DSS starting up.... [2011-11-28 15:19:53][Info][System] dSS v1.3.0 (3d8a40ebbea7fb09bb659c91858a27f5b3fa0bcd) (root@scientist-Latitude-D630) [2011-11-28 15:19:53][Info][System] Configuration: [2011-11-28 15:19:53][Info][System] data: '../data/' [2011-11-28 15:19:53][Info][System] config: '../data/' [2011-11-28 15:19:53][Info][System] webroot: '../data/webroot/' [2011-11-28 15:19:53][Info][System] log dir: '../data/logs/' [2011-11-28 15:19:53][Info][System] props dir: '../data/' [2011-11-28 15:19:53][Warning][System] Event "send_email" is deprecated, and should be substituted by "sendmail". [2011-11-28 15:19:53][Info][Apartment] Found ../data/apartment.xml [2011-11-28 15:19:53][Debug][Metering] Metering::getSeries: Trying to load series from '../data/metering/3504175fe0000000ffc00013_energy_5minutely.xml' [2011-11-28 15:19:53][Debug][System] SeriesReader::readFromXML: could not open file: '../data/metering/3504175fe0000000ffc00013_energy_5minutely.xml' [2011-11-28 15:19:53][Debug][Metering] Metering::getSeries: Failed to load series, creating a new one [2011-11-28 15:19:53][Debug][System] No initial metering value found for meter 3504175fe0000000ffc00013 [2011-11-28 15:19:53][Debug][Metering] Metering::getSeries: Trying to load series from '../data/metering/3504175fe0000000ffc00010_energy_5minutely.xml' [2011-11-28 15:19:53][Debug][System] SeriesReader::readFromXML: could not open file: '../data/metering/3504175fe0000000ffc00010_energy_5minutely.xml' [2011-11-28 15:19:53][Debug][Metering] Metering::getSeries: Failed to load series, creating a new one [2011-11-28 15:19:53][Debug][System] No initial metering value found for meter 3504175fe0000000ffc00010 [2011-11-28 15:19:53][Info][DSSim] DSSim::createJSPluginFrom: Found device with id: example.js-device [2011-11-28 15:19:53][Info][DSSim] DSSim::createJSPluginFrom: adding script-file: data/simulated_device.js [2011-11-28 15:19:53][Error][DSSim] DSSim::createJSPluginFrom: cannot find script file 'data/simulated_device.js', skipping device example.js-device [2011-11-28 15:19:53][Info][DSSim] DSSim::createJSPluginFrom: Found device with id: example.slim_player [2011-11-28 15:19:53][Info][DSSim] DSSim::createJSPluginFrom: adding script-file: ../jslib/dsid.js [2011-11-28 15:19:53][Info][DSSim] DSSim::createJSPluginFrom: adding script-file: ../examples/plugins/js/slimplayer.js [2011-11-28 15:19:53][Info][DSSim] DSSim::createJSPluginFrom: Found device with id: example.vlc_player [2011-11-28 15:19:53][Info][DSSim] DSSim::createJSPluginFrom: adding script-file: ../jslib/dsid.js [2011-11-28 15:19:53][Info][DSSim] DSSim::createJSPluginFrom: adding script-file: ../examples/plugins/js/vlc.js [2011-11-28 15:19:53][Debug][DSSim] LoadZones: found zone (4) [2011-11-28 15:19:53][Debug][DSSim] LoadDevices: found device [2011-11-28 15:19:53][Debug][DSSim] LoadDevices: found device [2011-11-28 15:19:53][Debug][DSSim] LoadZones: found zone (1) [2011-11-28 15:19:53][Debug][DSSim] LoadDevices: found device [2011-11-28 15:19:53][Debug][DSSim] LoadDevices: found device [2011-11-28 15:19:53][Debug][DSSim] LoadGroups: Adding device 4 to group 1 in zone 1 [2011-11-28 15:19:53][Debug][DSSim] LoadGroups: Adding device 13 to group 1 in zone 1 [2011-11-28 15:19:53][Debug][DSSim] LoadZones: found zone (4) [2011-11-28 15:19:53][Debug][DSSim] LoadDevices: found device [2011-11-28 15:19:53][Debug][DSSim] LoadDevices: found device [2011-11-28 15:19:53][Debug][DSSim] LoadGroups: Adding device 5 to group 1 in zone 4 [2011-11-28 15:19:53][Debug][DSSim] LoadZones: found zone (172) [2011-11-28 15:19:53][Debug][DSSim] LoadDevices: found device [2011-11-28 15:19:53][Debug][DSBusInterface] initializing DSBusInterface [2011-11-28 15:19:54][Debug][DSBusInterface] Successfully connected to tcp://localhost:8442 [ 35 04 17 5f e0 00 00 f0 00 00 00 01 ] [2011-11-28 15:19:54][Info][WebServer] Webserver: Listening on 0.0.0.0:8080s [2011-11-28 15:19:54][Info][WebServer] Webserver: Configured webroot: ../data/webroot/ [2011-11-28 15:19:54][Info][WebServer] Webserver: Configured SSL certificate: ../data/dsscert.pem [2011-11-28 15:19:54][Info][WebServer] Webserver started [2011-11-28 15:19:54][Debug][WebServices] initializing WebServices [2011-11-28 15:19:55][Debug][EventInterpreter] Loading subscriptions from '../data/subscriptions.xml' [2011-11-28 15:19:55][Info][System] Using internal authentication mechanism. [2011-11-28 15:19:55][Error][System] PropertySystem::loadFromXML: Could not open file ../data/security.xml [2011-11-28 15:19:55][Info][System] Logged in as system user (Main thread needs system privileges) [2011-11-28 15:19:55][Debug][System] creating thread for "Apartment" [2011-11-28 15:19:55][Debug][System] creating thread for "DSBusInterface" [2011-11-28 15:19:55][Info][System] Logged in as system user (ModelMaintenance needs system-rights) [2011-11-28 15:19:55][Debug][System] creating thread for "WebServices" [2011-11-28 15:19:55][Info][Apartment] ModelMaintenance::execute: Enumerating model [2011-11-28 15:19:55][Debug][System] creating thread for "EventInterpreter" [2011-11-28 15:19:55][Debug][System] creating thread for "WebServicesWorker" [2011-11-28 15:19:55][Debug][System] creating thread for "BonjourHandler" [2011-11-28 15:19:55][Debug][System] creating thread for "WebServicesWorker" [2011-11-28 15:19:55][Info][EventInterpreter] Queue: New event 'running' in queue... [2011-11-28 15:19:55][Info][System] Logged in as system user (EventInterpreter needs to run as system user (for now)) [2011-11-28 15:19:55][Info][Apartment] Got bus ready event. [2011-11-28 15:19:55][Debug][EventInterpreter] Got event from queue: 'running' [2011-11-28 15:19:55][Debug][EventInterpreter] Subscription 'running_javascript' matches event [2011-11-28 15:19:55][Debug][EventInterpreter] Found handler 'javascript' calling... [2011-11-28 15:19:55][Debug][Apartment] Discovered device with DSID: 3504175fe0000000ffc00013 [2011-11-28 15:19:55][Debug][Apartment] dSM present [2011-11-28 15:19:55][Debug][Apartment] Discovered device with DSID: 3504175fe0000000ffc00010 [2011-11-28 15:19:55][Debug][Apartment] dSM present [2011-11-28 15:19:55][Info][EventInterpreter] Queue: New event 'EventInterpreterPluginJavascript_cleanupScripts' in queue... [2011-11-28 15:19:55][Debug][System] creating thread for "WebServicesWorker" [2011-11-28 15:19:55][Info][System] Logged in as system user (Bonjour needs system rights) [2011-11-28 15:19:55][Debug][System] creating thread for "WebServicesWorker" [2011-11-28 15:19:55][Debug][Apartment] Discovered device with DSID: 3504175fe0000000ffc00013 [2011-11-28 15:19:55][Debug][Apartment] dSM present [2011-11-28 15:19:55][Debug][Apartment] Discovered device with DSID: 3504175fe0000000ffc00010 [2011-11-28 15:19:55][Debug][Apartment] dSM present [2011-11-28 15:19:55][Debug][EventInterpreter] EQueue::scheduleFromEvent: Event has a valid time, rescheduling at 2011-11-28 15:20:15 [2011-11-28 15:19:55][Debug][System] EventInterpreterPluginJavascript::handleEvent: running script /home/scientist/dss-1.3.0/data/solar_computer.js [2011-11-28 15:19:55][Info][System] Adding service 'dSS' [2011-11-28 15:19:55][Info][EventInterpreter] Queue: New timed-event 'solar_computer.update' in queue... [2011-11-28 15:19:55][Debug][EventInterpreter] Queue::scheduleFromEvent: Event "solar_computer.update" has a ICalRule rescheduling at 20111128T000100 with Rule FREQ=DAILY [2011-11-28 15:19:55][Debug][System] Destroying thread: DSBusInterface [2011-11-28 15:19:55][Debug][EventInterpreter] called. [2011-11-28 15:19:55][Debug][EventInterpreter] Done processing event 'running' [2011-11-28 15:19:55][Info][System] Service 'dSS' successfully established. [2011-11-28 15:19:56][Info][Apartment] DSMeter with DSID: 3504175fe0000000ffc00013 is ready [2011-11-28 15:19:56][Info][System] scanDSMeter: Start 3504175fe0000000ffc00013 [2011-11-28 15:19:56][Debug][System] scanDSMeter: Found zone with id: 4 [2011-11-28 15:19:56][Debug][System] scanDeviceOnBus: Found device with address: 11 [2011-11-28 15:19:56][Debug][System] scanDeviceOnBus: DSID: 3504175fe0000000ffc00011 [2011-11-28 15:19:56][Debug][System] scanDeviceOnBus: Function-ID: 0, Product-ID: 0, Revision-ID: 0 [2011-11-28 15:19:56][Info][EventInterpreter] Queue: New event 'new_device' in queue... [2011-11-28 15:19:56][Debug][EventInterpreter] Got event from queue: 'new_device' [2011-11-28 15:19:56][Info][EventInterpreter] Queue: New event 'dsMeter_ready' in queue... [2011-11-28 15:19:56][Debug][EventInterpreter] Parameter 'device' = '3504175fe0000000ffc00011' [2011-11-28 15:19:56][Debug][EventInterpreter] Parameter 'zone' = '4' [2011-11-28 15:19:56][Debug][EventInterpreter] Done processing event 'new_device' [2011-11-28 15:19:56][Debug][EventInterpreter] Got event from queue: 'dsMeter_ready' [2011-11-28 15:19:56][Debug][EventInterpreter] Parameter 'dsMeter' = '3504175fe0000000ffc00013' [2011-11-28 15:19:56][Debug][EventInterpreter] Done processing event 'dsMeter_ready' [2011-11-28 15:19:57][Info][Apartment] DSMeter with DSID: 3504175fe0000000ffc00010 is ready [2011-11-28 15:19:57][Info][System] scanDSMeter: Start 3504175fe0000000ffc00010 [2011-11-28 15:19:57][Debug][System] scanDSMeter: Found zone with id: 1 [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Found device with address: 4 [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: DSID: 3504175fe0000000ffc00004 [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Function-ID: 0, Product-ID: 0, Revision-ID: 0 [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: adding device 4 to group 1 [2011-11-28 15:19:57][Info][EventInterpreter] Queue: New event 'new_device' in queue... [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Found device with address: 13 [2011-11-28 15:19:57][Debug][EventInterpreter] Got event from queue: 'new_device' [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: DSID: 3504175fe0000000ffc00013 [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'device' = '3504175fe0000000ffc00004' [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'zone' = '1' [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Function-ID: 0, Product-ID: 0, Revision-ID: 0 [2011-11-28 15:19:57][Debug][EventInterpreter] Done processing event 'new_device' [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: adding device 13 to group 1 [2011-11-28 15:19:57][Info][EventInterpreter] Queue: New event 'new_device' in queue... [2011-11-28 15:19:57][Debug][System] scanDSMeter: Found group with id: 1 [2011-11-28 15:19:57][Debug][EventInterpreter] Got event from queue: 'new_device' [2011-11-28 15:19:57][Debug][System] scanDSMeter: Found zone with id: 4 [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'device' = '3504175fe0000000ffc00013' [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'zone' = '1' [2011-11-28 15:19:57][Debug][EventInterpreter] Done processing event 'new_device' [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Found device with address: 3 [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: DSID: 3504175fe0000000ffc00003 [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Function-ID: 0, Product-ID: 0, Revision-ID: 0 [2011-11-28 15:19:57][Info][EventInterpreter] Queue: New event 'new_device' in queue... [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Found device with address: 5 [2011-11-28 15:19:57][Debug][EventInterpreter] Got event from queue: 'new_device' [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: DSID: 3504175fe0000000ffc00005 [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'device' = '3504175fe0000000ffc00003' [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'zone' = '4' [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Function-ID: 0, Product-ID: 0, Revision-ID: 0 [2011-11-28 15:19:57][Debug][EventInterpreter] Done processing event 'new_device' [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: adding device 5 to group 1 [2011-11-28 15:19:57][Info][EventInterpreter] Queue: New event 'new_device' in queue... [2011-11-28 15:19:57][Debug][System] scanDSMeter: Found group with id: 1 [2011-11-28 15:19:57][Debug][EventInterpreter] Got event from queue: 'new_device' [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'device' = '3504175fe0000000ffc00005' [2011-11-28 15:19:57][Debug][System] scanDSMeter: Found zone with id: 172 [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'zone' = '4' [2011-11-28 15:19:57][Debug][EventInterpreter] Done processing event 'new_device' [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Found device with address: 7 [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: DSID: 3504175fe0000000ffc00007 [2011-11-28 15:19:57][Debug][System] scanDeviceOnBus: Function-ID: 0, Product-ID: 0, Revision-ID: 0 [2011-11-28 15:19:57][Info][EventInterpreter] Queue: New event 'new_device' in queue... [2011-11-28 15:19:57][Debug][EventInterpreter] Got event from queue: 'new_device' [2011-11-28 15:19:57][Info][EventInterpreter] Queue: New event 'dsMeter_ready' in queue... [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'device' = '3504175fe0000000ffc00007' [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'zone' = '172' [2011-11-28 15:19:57][Debug][EventInterpreter] Done processing event 'new_device' [2011-11-28 15:19:57][Debug][EventInterpreter] Got event from queue: 'dsMeter_ready' [2011-11-28 15:19:57][Debug][EventInterpreter] Parameter 'dsMeter' = '3504175fe0000000ffc00010' [2011-11-28 15:19:57][Debug][EventInterpreter] Done processing event 'dsMeter_ready' [2011-11-28 15:19:58][Info][Apartment] ******** Finished loading model from dSM(s)... [2011-11-28 15:19:58][Info][EventInterpreter] Queue: New event 'model_ready' in queue... [2011-11-28 15:19:58][Debug][EventInterpreter] Got event from queue: 'model_ready' [2011-11-28 15:19:58][Debug][EventInterpreter] Done processing event 'model_ready' [2011-11-28 15:20:15][Info][EventInterpreter] Queue: New event 'EventInterpreterPluginJavascript_cleanupScripts' in queue... [2011-11-28 15:20:15][Debug][EventInterpreter] Got event from queue: 'EventInterpreterPluginJavascript_cleanupScripts' [2011-11-28 15:20:15][Debug][EventInterpreter] Subscription 'EventInterpreterPluginJavascript_cleanupScripts_internal_relay' matches event [2011-11-28 15:20:15][Debug][EventInterpreter] Found handler 'internal_relay' calling... [2011-11-28 15:20:15][Info][EventInterpreter] Queue: New event 'EventInterpreterPluginJavascript_cleanupScripts' in queue... [2011-11-28 15:20:15][Debug][EventInterpreter] EQueue::scheduleFromEvent: Event has a valid time, rescheduling at 2011-11-28 15:20:35 [2011-11-28 15:20:15][Debug][EventInterpreter] called. [2011-11-28 15:20:15][Debug][EventInterpreter] Done processing event 'EventInterpreterPluginJavascript_cleanupScripts' [2011-11-28 15:20:35][Info][EventInterpreter] Queue: New event 'EventInterpreterPluginJavascript_cleanupScripts' in queue... [2011-11-28 15:20:35][Debug][EventInterpreter] Got event from queue: 'EventInterpreterPluginJavascript_cleanupScripts' [2011-11-28 15:20:35][Debug][EventInterpreter] Subscription 'EventInterpreterPluginJavascript_cleanupScripts_internal_relay' matches event [2011-11-28 15:20:35][Debug][EventInterpreter] Found handler 'internal_relay' calling... [2011-11-28 15:20:35][Info][EventInterpreter] Queue: New event 'EventInterpreterPluginJavascript_cleanupScripts' in queue... [2011-11-28 15:20:35][Debug][EventInterpreter] EQueue::scheduleFromEvent: Event has a valid time, rescheduling at 2011-11-28 15:20:55 [2011-11-28 15:20:35][Debug][EventInterpreter] called. [2011-11-28 15:20:35][Debug][EventInterpreter] Done processing event 'EventInterpreterPluginJavascript_cleanupScripts'