This page last changed on Jan 08, 2014 by juha.

Hello,
first thanks for this great home automation solution. I am working with this solution for a while without any problems.

But now I have a problem with the sensor polling and need some hints how to get the reason to solve this problem.

I am using following OR version: OpenRemote-Controller-2.1.0_SNAPSHOT-2013-06-17

The sensor polling is always working for 2-3 days. After it stops and I have to restart OR. I think it stops always after a "isNight" rule which I have configured in the system for starting some house ligths.

My simple rule configuration:

rule "Night Rule"

when

  CustomState(source=="DateTime isNight Sensor", value=="true")

then
  System.out.println ( "DateTime isNight Sensor -> Start Night Rule");
  execute.command("Licht Aussen Treppe Garten An");
  execute.command("Licht Treppe Eingang vorne An");
  execute.command("ipcamKellerHinten IR An");
  System.out.println ( "DateTime isNight Sensor -> Licht aussen an");

end

I see following traces in the dev.log:

2013-12-18 15:53:58,351 TRACE [Polling Sensor Thread ID = 3059656, Name ='Cron Hecke STATUS']: Processed 'off', receive
d 'off'
2013-12-18 15:53:58,352 TRACE [Polling Sensor Thread ID = 3059477, Name ='Cron Sprenger Rasen STATUS']: Processed 'off'
, received 'off'
2013-12-18 15:53:58,848 TRACE [Polling Sensor Thread ID = 3059659, Name ='Cron Sprenger Haus linke Seite am Zaun STATUS
']: Processed 'off', received 'off'
2013-12-18 15:53:58,850 TRACE [Polling Sensor Thread ID = 3059658, Name ='Cron mobile Sprenger STATUS']: Processed 'off
', received 'off'
2013-12-18 15:53:58,851 TRACE [Polling Sensor Thread ID = 3059655, Name ='Cron Sprenger vorne STATUS']: Processed 'off'
, received 'off'
2013-12-18 15:53:58,852 TRACE [Polling Sensor Thread ID = 3069813, Name ='Cron Pumpe Pool STATUS']: Processed 'off', re
ceived 'off'
2013-12-18 15:53:58,852 TRACE [Polling Sensor Thread ID = 3059656, Name ='Cron Hecke STATUS']: Processed 'off', receive
d 'off'
2013-12-18 15:53:58,853 TRACE [Polling Sensor Thread ID = 3059477, Name ='Cron Sprenger Rasen STATUS']: Processed 'off'
, received 'off'
2013-12-18 15:53:58,929 TRACE [Polling thread for sensor: DateTime isNight Sensor]: Processed 'true', received 'true'
2013-12-18 15:53:59,349 TRACE [Polling Sensor Thread ID = 3059659, Name ='Cron Sprenger Haus linke Seite am Zaun STATUS
']: Processed 'off', received 'off'
2013-12-18 15:53:59,351 TRACE [Polling Sensor Thread ID = 3059658, Name ='Cron mobile Sprenger STATUS']: Processed 'off
', received 'off'
2013-12-18 15:53:59,351 TRACE [Polling Sensor Thread ID = 3059655, Name ='Cron Sprenger vorne STATUS']: Processed 'off'
, received 'off'
2013-12-18 15:53:59,352 TRACE [Polling Sensor Thread ID = 3069813, Name ='Cron Pumpe Pool STATUS']: Processed 'off', re
ceived 'off'
2013-12-18 15:53:59,353 TRACE [Polling Sensor Thread ID = 3059656, Name ='Cron Hecke STATUS']: Processed 'off', receive
d 'off'
2013-12-18 15:53:59,353 TRACE [Polling Sensor Thread ID = 3059477, Name ='Cron Sprenger Rasen STATUS']: Processed 'off'
, received 'off'
2013-12-18 15:54:28,715 TRACE [Polling thread for sensor: DisplayDate Sensor]: Processed '18.12.2013', received '18.12.
2013'
2013-12-18 15:54:33,920 INFO [Polling thread for sensor: Licht Treppe Eingang vorne]: received message: 0
2013-12-18 15:54:33,920 TRACE [Polling thread for sensor: Licht Treppe Eingang vorne]: Processed '0', received '0'
2013-12-18 15:54:52,641 TRACE [Polling thread for sensor: DateTime isDay Sensor]: Processed 'false', received 'false'
2013-12-18 16:00:55,764 INFO [Polling thread for sensor: TempKinderzimmer]: received message: 20.00
2013-12-18 16:00:55,765 TRACE [Polling thread for sensor: TempKinderzimmer]: Processed '20.00', received '20.00'
2013-12-18 16:00:58,527 INFO [Polling thread for sensor: TempUmkleide]: received message: 20.50
2013-12-18 16:00:58,528 TRACE [Polling thread for sensor: TempUmkleide]: Processed '20.50', received '20.50'
2013-12-18 16:00:58,653 INFO [Polling thread for sensor: TempBad]: received message: 21.00
2013-12-18 16:00:58,653 TRACE [Polling thread for sensor: TempBad]: Processed '21.00', received '21.00'
2013-12-18 16:00:58,758 INFO [Polling thread for sensor: TempSchlafzimmer]: received message: 19.56
2013-12-18 16:00:58,758 TRACE [Polling thread for sensor: TempSchlafzimmer]: Processed '19.56', received '19.56'
2013-12-18 16:00:59,592 INFO [Polling thread for sensor: TempEsszimmer]: received message: 21.62
2013-12-18 16:00:59,593 TRACE [Polling thread for sensor: TempEsszimmer]: Processed '21.62', received '21.62'
2013-12-18 16:00:59,610 INFO [Polling thread for sensor: TempArbeitszimmer]: received message: 22.94
2013-12-18 16:00:59,610 TRACE [Polling thread for sensor: TempArbeitszimmer]: Processed '22.94', received '22.94'
2013-12-18 16:01:04,984 INFO [Polling thread for sensor: TempKeller3]: received message: 22.56
2013-12-18 16:01:04,985 TRACE [Polling thread for sensor: TempKeller3]: Processed '22.56', received '22.56'
2013-12-18 16:04:53,475 INFO [HTTP-Thread-1173]: Querying changed state from ChangedStatus table...
2013-12-18 16:04:53,476 INFO [HTTP-Thread-1173]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [2643396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241]] in ChangedStatus table.
2013-12-18 16:04:53,476 INFO [HTTP-Thread-1173]: Got the skipped sensor ids of statuses in ChangedStatusRecord:FFFFFFFF
07EC0C03465C4CE58948D743C08BDCEC-[2643396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241] sensorID:[264
3396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241] statusChangedSensorID:[2643396]
2013-12-18 16:04:53,476 INFO [HTTP-Thread-1173]: Querying changed data from StatusCache...
2013-12-18 16:04:53,476 INFO [HTTP-Thread-1173]: Have queried changed data from StatusCache.
2013-12-18 16:04:53,477 INFO [HTTP-Thread-1173]: Return the polling status.
2013-12-18 16:04:53,478 INFO [HTTP-Thread-1173]: Finished polling at 2013-12-18 16:04:53

2013-12-18 16:04:53,496 INFO [HTTP-Thread-1173]: Querying changed state from ChangedStatus table...
2013-12-18 16:04:53,497 INFO [HTTP-Thread-1173]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [2643396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241]] in ChangedStatus table.
2013-12-18 16:04:53,497 INFO [HTTP-Thread-1173]: ChangedStatusRecord:FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC-[2643396,
 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241] sensorID:[2643396, 2643408, 3059477, 3059655, 3059656, 
3059658, 3069813, 3671241] statusChangedSensorID:[]Waiting...
2013-12-18 16:04:55,007 INFO [HTTP-Thread-1174]: Querying changed state from ChangedStatus table...
2013-12-18 16:04:55,008 INFO [HTTP-Thread-1174]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [2643396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241]] in ChangedStatus table.
2013-12-18 16:04:55,008 INFO [HTTP-Thread-1174]: ChangedStatusRecord:FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC-[2643396,
 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241] sensorID:[2643396, 2643408, 3059477, 3059655, 3059656, 
3059658, 3069813, 3671241] statusChangedSensorID:[]Waiting...
2013-12-18 16:04:57,427 INFO [HTTP-Thread-1175]: Querying changed state from ChangedStatus table...
2013-12-18 16:04:57,427 INFO [HTTP-Thread-1175]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [3066314, 3066321, 3066322, 3066323, 3066324, 3066325, 3066326]] in ChangedStatus table.
2013-12-18 16:04:57,428 INFO [HTTP-Thread-1175]: Got the skipped sensor ids of statuses in ChangedStatusRecord:FFFFFFFF
07EC0C03465C4CE58948D743C08BDCEC-[3066314, 3066321, 3066322, 3066323, 3066324, 3066325, 3066326] sensorID:[3066314, 306
6321, 3066322, 3066323, 3066324, 3066325, 3066326] statusChangedSensorID:[3066314, 3066323, 3066322, 3066321, 3066326, 
3066325, 3066324]
2013-12-18 16:04:57,428 INFO [HTTP-Thread-1175]: Querying changed data from StatusCache...
2013-12-18 16:04:57,428 INFO [HTTP-Thread-1175]: Have queried changed data from StatusCache.
2013-12-18 16:04:57,428 INFO [HTTP-Thread-1175]: Return the polling status.
2013-12-18 16:04:57,429 INFO [HTTP-Thread-1175]: Finished polling at 2013-12-18 16:04:57

2013-12-18 16:04:57,444 INFO [HTTP-Thread-1175]: Querying changed state from ChangedStatus table...
2013-12-18 16:04:57,445 INFO [HTTP-Thread-1175]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [3066314, 3066321, 3066322, 3066323, 3066324, 3066325, 3066326]] in ChangedStatus table.
2013-12-18 16:04:57,445 INFO [HTTP-Thread-1175]: ChangedStatusRecord:FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC-[3066314,
 3066321, 3066322, 3066323, 3066324, 3066325, 3066326] sensorID:[3066314, 3066321, 3066322, 3066323, 3066324, 3066325, 
3066326] statusChangedSensorID:[]Waiting...
2013-12-18 16:05:00,009 INFO [HTTP-Thread-1176]: Querying changed state from ChangedStatus table...
2013-12-18 16:05:00,009 INFO [HTTP-Thread-1176]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [2643396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241]] in ChangedStatus table.
2013-12-18 16:05:00,010 INFO [HTTP-Thread-1176]: ChangedStatusRecord:FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC-[2643396,
 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241] sensorID:[2643396, 2643408, 3059477, 3059655, 3059656, 
3059658, 3069813, 3671241] statusChangedSensorID:[]Waiting...
2013-12-18 16:05:08,926 INFO [HTTP-Thread-1177]: Querying changed state from ChangedStatus table...
2013-12-18 16:05:08,926 INFO [HTTP-Thread-1177]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [2643396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241]] in ChangedStatus table.
2013-12-18 16:05:08,927 INFO [HTTP-Thread-1177]: ChangedStatusRecord:FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC-[2643396,
 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241] sensorID:[2643396, 2643408, 3059477, 3059655, 3059656, 
3059658, 3069813, 3671241] statusChangedSensorID:[]Waiting...
2013-12-18 16:05:10,183 INFO [HTTP-Thread-1178]: Querying changed state from ChangedStatus table...
2013-12-18 16:05:10,183 INFO [HTTP-Thread-1178]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [3066314, 3066321, 3066322, 3066323, 3066324, 3066325, 3066326]] in ChangedStatus table.
2013-12-18 16:05:10,184 INFO [HTTP-Thread-1178]: ChangedStatusRecord:FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC-[3066314,
 3066321, 3066322, 3066323, 3066324, 3066325, 3066326] sensorID:[3066314, 3066321, 3066322, 3066323, 3066324, 3066325, 
3066326] statusChangedSensorID:[]Waiting...
2013-12-18 16:05:21,516 INFO [HTTP-Thread-1179]: Querying changed state from ChangedStatus table...
2013-12-18 16:05:21,517 INFO [HTTP-Thread-1179]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [2643396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241]] in ChangedStatus table.
2013-12-18 16:05:21,517 INFO [HTTP-Thread-1179]: ChangedStatusRecord:FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC-[2643396,
 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241] sensorID:[2643396, 2643408, 3059477, 3059655, 3059656, 
3059658, 3069813, 3671241] statusChangedSensorID:[]Waiting...
2013-12-18 16:05:43,497 INFO [HTTP-Thread-1173]: Had timeout for waiting status change.
2013-12-18 16:05:43,499 INFO [HTTP-Thread-1173]: Finished polling at 2013-12-18 16:05:43

2013-12-18 16:05:45,009 INFO [HTTP-Thread-1174]: Had timeout for waiting status change.
2013-12-18 16:05:45,010 INFO [HTTP-Thread-1174]: Finished polling at 2013-12-18 16:05:45

2013-12-18 16:05:47,445 INFO [HTTP-Thread-1175]: Had timeout for waiting status change.
2013-12-18 16:05:47,447 INFO [HTTP-Thread-1175]: Finished polling at 2013-12-18 16:05:47

2013-12-18 16:05:50,010 INFO [HTTP-Thread-1176]: Had timeout for waiting status change.
2013-12-18 16:05:50,011 INFO [HTTP-Thread-1176]: Finished polling at 2013-12-18 16:05:50

2013-12-18 16:05:58,927 INFO [HTTP-Thread-1177]: Had timeout for waiting status change.
2013-12-18 16:05:58,928 INFO [HTTP-Thread-1177]: Finished polling at 2013-12-18 16:05:58

2013-12-18 16:06:00,184 INFO [HTTP-Thread-1178]: Had timeout for waiting status change.
2013-12-18 16:06:00,185 INFO [HTTP-Thread-1178]: Finished polling at 2013-12-18 16:06:00

2013-12-18 16:06:11,517 INFO [HTTP-Thread-1179]: Had timeout for waiting status change.
2013-12-18 16:06:11,519 INFO [HTTP-Thread-1179]: Finished polling at 2013-12-18 16:06:11

2013-12-18 16:07:23,308 INFO [HTTP-Thread-1177]: Querying changed state from ChangedStatus table...
2013-12-18 16:07:23,309 INFO [HTTP-Thread-1177]: Found: [device => FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC, sensorIDs 
=> [2643396, 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241]] in ChangedStatus table.
2013-12-18 16:07:23,309 INFO [HTTP-Thread-1177]: ChangedStatusRecord:FFFFFFFF07EC0C03465C4CE58948D743C08BDCEC-[2643396,
 2643408, 3059477, 3059655, 3059656, 3059658, 3069813, 3671241] sensorID:[2643396, 2643408, 3059477, 3059655, 3059656, 
3059658, 3069813, 3671241] statusChangedSensorID:[]Waiting... 

I will deactivate all actual not used rules like watering and will start deeper looking into the rule processing.

Any hints how to start digging into this problem?

E.g. how to improve the rules logging with more informations for the sensor polling?

Thanks in advance!

Regards
Sebastian

I am having the same issue however in my case I do not have any rules associated. The sensor just stops updating after a while.

Posted by iloveautomation at Jan 04, 2014 23:57

Hmm, nothing there in the log that would indicate an obvious error.

Which sensor stops polling, or all of them do?

Posted by juha at Jan 08, 2014 19:04

In my case it is only the sensor connected to a telnet command. Right now all I do is resync the controller with the composer and then it starts up polling for a period of time.
When I look at the logs there is not standing out.

Posted by iloveautomation at Jan 11, 2014 02:07
Document generated by Confluence on Jun 05, 2016 09:38