Зависание движка правил

Здравствуйте.
Тестирую следующее правило.

var motion_timer_id = null;

  defineRule("Motion", 
  {
      whenChanged: "SensorWB-MSW1/Current Motion",
      then: function(newValue, devName, cellName) 
      {
        	if ( newValue > 300) 
          	{  
        		dev["DimmerRGBW1"]["White"] = 32;
              		if (motion_timer_id) { clearTimeout(motion_timer_id); }

              		motion_timer_id = setTimeout(function() 
                        {
                  		dev["DimmerRGBW1"]["White"] = 0;
                  		motion_timer_id = null;
              		}, 5000);
               }
      }
  });

Правило практически скопировано из примера в документации.
При срабатывании датчика движения включается LED, и выключается с задержкой 5 сек после “пропадания” движения. Если “количество” движения более 300 ед непродолжительно, то все работает корректно, но если двигаться долго (примерно более 30 сек и более), то движок зависает, и висит около 5 мин, потом сам откисает.
Я подозреваю таймер, а именно то, что движку становиться плохо от многократных подряд установок и сбросов таймера.
Есть ли решение данной проблемы?

Добрый день!

Подскажите, пожалуйста, версию движка правил:
dpkg -s wb-rules

Проблема была обнаружена когда была установлена версия 1.7, и сохранилась после обновления до 2.2. Кстати, обновление создало дополнительные проблемы - не работало "dev[“DimmerRGBW1”][“White”] = 32; - “White” был не “writable”.

Добрый день!

С какой периодичностью обновляется значение “SensorWB-MSW1/Current Motion”?
И можете показать что в логах в момент зависания?

Здравствуйте.
Все настройки дефолтные.
Датчик опрашивается контроллером раз в 20ms.
В момент зависания в /var/log/messages тишина. Когда откисает:

Apr 13 11:25:03 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: driver is created
Apr 13 11:25:03 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [wbgo_mqtt] rules-wirenboard-AGLNKPX3-3324: MQTT connection established
Apr 13 11:25:03 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: driver loop is started
Apr 13 11:25:03 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: wait for driver to become ready
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: WARNING: [device] Unknown metadata for device wb-homa-rcd: ‘noolite_remotes_custom’
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: [driver] failed to accept new meta ‘noolite_remotes_custom’ on device wb-homa-rc d: Unknown device meta type
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: WARNING: [device] Unknown metadata for device wb-homa-rcd: ‘noolite_remotes’
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: [driver] failed to accept new meta ‘noolite_remotes’ on device wb-homa-rcd: Unkn own device meta type
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: WARNING: [device] Unknown metadata for device wb-homa-rcd: ‘room’
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: [driver] failed to accept new meta ‘room’ on device wb-homa-rcd: Unknown device meta type
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: WARNING: [device] Unknown metadata for device wb-homa-rcd: ‘rssi_threshold’
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: [driver] failed to accept new meta ‘rssi_threshold’ on device wb-homa-rcd: Unkno wn device meta type
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: driver is ready
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [rule info] using file /var/lib/wirenboard/wbrules-persistent.db for persistent D B
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [wbgo_mqtt] wb-rules-engine-wirenboard-AGLNKPX3-3324: MQTT connection established
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [engine] Starting main loop
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: the engine is ready
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [engine] Starting sync loop
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/buzzer.js is NOT under source root /etc/wb-rules
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/hwmon.js is NOT under source root /etc/wb-rules
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/network.js is NOT under source root /etc/wb-rule s
Apr 13 11:25:05 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/power_status.js is NOT under source root /etc/wb -rules
Apr 13 11:25:05 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: command ‘/bin/sh -c echo 0 > /sys/class/pwm/pwmchip0/export’ failed with exit s tatus 1
Apr 13 11:25:05 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/system.js is NOT under source root /etc/wb-rules
Apr 13 11:25:05 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/wb-mqtt-dac.js is NOT under source root /etc/wb- rules
Apr 13 11:25:06 wirenboard-AGLNKPX3 authpriv.info CRON[3279]: pam_unix(cron:session): session closed for user root
Apr 13 11:25:06 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [rule info] add your rules to /etc/wb-rules/
Apr 13 11:25:06 wirenboard-AGLNKPX3 user.notice serial: ModbusRTU::ReadRegisterRange(): failed to read 3 holding(s) @ 6 of device modbus:24: Serial pro tocol error: request timed out
Apr 13 11:25:06 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules/load_alarms.js is NOT under source root /etc/wb-rules
Apr 13 11:25:06 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: all rule files are loaded

Пока сделал так:

var motion_timer_id = null;

var OnLigth = 0;
var SetTime = 0;

  defineRule("Motion", 
  {
      whenChanged: "SensorWB-MSW1/Current Motion",
      then: function(newValue, devName, cellName) 
      {
        	if ( newValue > 300 && OnLigth == 0) 
          	{  
        		    dev["DimmerRGBW1"]["White"] = 32;
              		OnLigth = 1;
              		SetTime = 0;
            }
        	if ( OnLigth == 1 && newValue <= 300 && SetTime == 0 )
            {
                    motion_timer_id = setTimeout(function() 
                    {
                  		 dev["DimmerRGBW1"]["White"] = 0;
                  	     motion_timer_id = null;
                         OnLigth = 0;
                         SetTime = 0;
              		}, 
                    5000);
                    SetTime = 1;
            }
        	if ( SetTime == 1 && newValue > 300 )
            {
                if (motion_timer_id) { clearTimeout(motion_timer_id); }
                SetTime = 0;
            }
      }
  });

Да, костыли. Да, некрасиво.
Но работает, по крайней мере.

Добрый день.

А можете показать последние записи в логи от wb-rules перед вот этим зависанием?
Интересны именно последовательные записи из одного лога: сначала строки перед зависанием, потом строки, которые первые появляются после него.

Также уточните, пожалуйста: в промежутке, когда wb-rules завис и потом продолжил работу - выполнялись ли какие-то действия с ним, например, ручной рестарт сервиса?

Вот весь лог за это время. Зависание было около 11:20.

root@wirenboard-AGLNKPX3:~# tail -f /var/log/messages
Apr 13 11:17:14 wirenboard-AGLNKPX3 user.notice serial: ModbusRTU::ReadRegisterRange(): failed to read 3 holding(s) @ 32 of device modbus:24: Serial protocol error: request timed out
Apr 13 11:17:15 wirenboard-AGLNKPX3 user.notice serial: ModbusRTU::ReadRegisterRange(): failed to read 7 coil(s) @ 5300 of device m odbus:24: Serial protocol error: request timed out
Apr 13 11:17:21 wirenboard-AGLNKPX3 auth.info sshd[2707]: reprocess config line 30: Deprecated option RSAAuthentication
Apr 13 11:17:21 wirenboard-AGLNKPX3 auth.info sshd[2707]: reprocess config line 37: Deprecated option RhostsRSAAuthentication
Apr 13 11:17:27 wirenboard-AGLNKPX3 auth.info sshd[2707]: Accepted password for root from 192.168.5.123 port 60620 ssh2
Apr 13 11:17:27 wirenboard-AGLNKPX3 authpriv.info sshd[2707]: pam_unix(sshd:session): session opened for user root by (uid=0)
Apr 13 11:17:27 wirenboard-AGLNKPX3 authpriv.info systemd: pam_unix(systemd-user:session): session opened for user root by (uid=0)
Apr 13 11:18:01 wirenboard-AGLNKPX3 authpriv.info CRON[2810]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:18:01 wirenboard-AGLNKPX3 cron.info CRON[2814]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_confed.sh 2>&1 | logger -t wb-daemon-watchdogs)
Apr 13 11:18:05 wirenboard-AGLNKPX3 authpriv.info CRON[2810]: pam_unix(cron:session): session closed for user root
Apr 13 11:18:43 wirenboard-AGLNKPX3 user.notice wb-mqtt-db[535]: 2020-04-13 11:18:43.090 NOTICE: Bulk processing took 107ms
Apr 13 11:19:01 wirenboard-AGLNKPX3 authpriv.info CRON[2914]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:19:01 wirenboard-AGLNKPX3 cron.info CRON[2919]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_confed.sh 2>&1 | logger -t wb-daemon-watchdogs)
Apr 13 11:19:05 wirenboard-AGLNKPX3 authpriv.info CRON[2914]: pam_unix(cron:session): session closed for user root
Apr 13 11:20:01 wirenboard-AGLNKPX3 authpriv.info CRON[2988]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:20:01 wirenboard-AGLNKPX3 authpriv.info CRON[2989]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:20:01 wirenboard-AGLNKPX3 cron.info CRON[2996]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_confed.sh 2>&1 | logger -t wb-daemon-watchdogs)
Apr 13 11:20:01 wirenboard-AGLNKPX3 cron.info CRON[2997]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_wbrules.sh 2>&1 | logger -t wb-daemon-watchdogs)
Apr 13 11:20:03 wirenboard-AGLNKPX3 authpriv.info CRON[2989]: pam_unix(cron:session): session closed for user root
Apr 13 11:20:06 wirenboard-AGLNKPX3 authpriv.info CRON[2988]: pam_unix(cron:session): session closed for user root
Apr 13 11:20:43 wirenboard-AGLNKPX3 user.notice wb-mqtt-db[535]: 2020-04-13 11:20:43.099 NOTICE: Bulk processing took 115ms
Apr 13 11:21:01 wirenboard-AGLNKPX3 authpriv.info CRON[3052]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:21:01 wirenboard-AGLNKPX3 cron.info CRON[3056]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_confed.sh 2>&1 | logger -t wb-daemon-watchdogs)
Apr 13 11:21:05 wirenboard-AGLNKPX3 authpriv.info CRON[3052]: pam_unix(cron:session): session closed for user root
Apr 13 11:21:27 wirenboard-AGLNKPX3 daemon.info dhclient[3862]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 4
Apr 13 11:21:29 wirenboard-AGLNKPX3 user.notice serial: ModbusRTU::ReadRegisterRange(): failed to read 3 holding(s) @ 32 of device modbus:24: Serial protocol error: request timed out
Apr 13 11:21:31 wirenboard-AGLNKPX3 daemon.info dhclient[3862]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 8
Apr 13 11:21:39 wirenboard-AGLNKPX3 daemon.info dhclient[3862]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 14
Apr 13 11:21:53 wirenboard-AGLNKPX3 daemon.info dhclient[3862]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 15
Apr 13 11:22:01 wirenboard-AGLNKPX3 authpriv.info CRON[3106]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:22:01 wirenboard-AGLNKPX3 cron.info CRON[3110]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_confed.sh 2>&1 | logger -t wb-daemon-watchdogs)
Apr 13 11:22:05 wirenboard-AGLNKPX3 authpriv.info CRON[3106]: pam_unix(cron:session): session closed for user root
Apr 13 11:22:08 wirenboard-AGLNKPX3 daemon.info dhclient[3862]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 16
Apr 13 11:22:24 wirenboard-AGLNKPX3 daemon.info dhclient[3862]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 4
Apr 13 11:22:28 wirenboard-AGLNKPX3 daemon.info dhclient[3862]: No DHCPOFFERS received.
Apr 13 11:22:28 wirenboard-AGLNKPX3 daemon.info dhclient[3862]: No working leases in persistent database - sleeping.
Apr 13 11:22:43 wirenboard-AGLNKPX3 user.notice wb-mqtt-db[535]: 2020-04-13 11:22:43.109 NOTICE: Bulk processing took 126ms
Apr 13 11:23:02 wirenboard-AGLNKPX3 authpriv.info CRON[3165]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:23:02 wirenboard-AGLNKPX3 cron.info CRON[3169]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_confed.sh 2>&1 | logger -t wb-daemon-watchdogs)
Apr 13 11:23:06 wirenboard-AGLNKPX3 authpriv.info CRON[3165]: pam_unix(cron:session): session closed for user root
Apr 13 11:23:50 wirenboard-AGLNKPX3 user.notice serial: ModbusRTU::ReadRegisterRange(): failed to read 4 holding(s) @ 0 of device m odbus:24: Serial protocol error: request timed out
Apr 13 11:24:01 wirenboard-AGLNKPX3 authpriv.info CRON[3223]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:24:01 wirenboard-AGLNKPX3 cron.info CRON[3229]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_confed.sh 2>&1 | logger -t wb-daemon-watchdogs)
Apr 13 11:24:05 wirenboard-AGLNKPX3 authpriv.info CRON[3223]: pam_unix(cron:session): session closed for user root
Apr 13 11:24:43 wirenboard-AGLNKPX3 user.notice wb-mqtt-db[535]: 2020-04-13 11:24:43.078 NOTICE: Bulk processing took 95ms
Apr 13 11:25:01 wirenboard-AGLNKPX3 authpriv.info CRON[3280]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:25:01 wirenboard-AGLNKPX3 cron.info CRON[3286]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_wbrules.sh 2>&1 | logger -t wb-daemon-watchd ogs)
Apr 13 11:25:01 wirenboard-AGLNKPX3 authpriv.info CRON[3279]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 13 11:25:01 wirenboard-AGLNKPX3 cron.info CRON[3290]: (root) CMD (/usr/share/wb-daemon-watchdogs/check_confed.sh 2>&1 | logger -t wb-daemon-watchdo gs)
Apr 13 11:25:02 wirenboard-AGLNKPX3 user.notice serial: ModbusRTU::ReadRegisterRange(): failed to read 3 holding(s) @ 32 of device modbus:24: Serial pr otocol error: request timed out
Apr 13 11:25:01 wirenboard-AGLNKPX3 user.notice wb-daemon-watchdogs: wb-rules check failed, reload wb-rules
Apr 13 11:25:03 wirenboard-AGLNKPX3 authpriv.info CRON[3280]: pam_unix(cron:session): session closed for user root
Apr 13 11:25:03 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: driver is created
Apr 13 11:25:03 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [wbgo_mqtt] rules-wirenboard-AGLNKPX3-3324: MQTT connection established
Apr 13 11:25:03 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: driver loop is started
Apr 13 11:25:03 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: wait for driver to become ready
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: WARNING: [device] Unknown metadata for device wb-homa-rcd: ‘noolite_remotes_custom’
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: [driver] failed to accept new meta ‘noolite_remotes_custom’ on device wb-homa-rc d: Unknown device meta type
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: WARNING: [device] Unknown metadata for device wb-homa-rcd: ‘noolite_remotes’
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: [driver] failed to accept new meta ‘noolite_remotes’ on device wb-homa-rcd: Unkn own device meta type
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: WARNING: [device] Unknown metadata for device wb-homa-rcd: ‘room’
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: [driver] failed to accept new meta ‘room’ on device wb-homa-rcd: Unknown device meta type
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: WARNING: [device] Unknown metadata for device wb-homa-rcd: ‘rssi_threshold’
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: [driver] failed to accept new meta ‘rssi_threshold’ on device wb-homa-rcd: Unkno wn device meta type
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: driver is ready
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [rule info] using file /var/lib/wirenboard/wbrules-persistent.db for persistent D B
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [wbgo_mqtt] wb-rules-engine-wirenboard-AGLNKPX3-3324: MQTT connection established
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [engine] Starting main loop
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: the engine is ready
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [engine] Starting sync loop
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/buzzer.js is NOT under source root /etc/wb-rules
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/hwmon.js is NOT under source root /etc/wb-rules
Apr 13 11:25:04 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/network.js is NOT under source root /etc/wb-rule s
Apr 13 11:25:05 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/power_status.js is NOT under source root /etc/wb -rules
Apr 13 11:25:05 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: ERROR: command ‘/bin/sh -c echo 0 > /sys/class/pwm/pwmchip0/export’ failed with exit s tatus 1
Apr 13 11:25:05 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/system.js is NOT under source root /etc/wb-rules
Apr 13 11:25:05 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules-system/rules/wb-mqtt-dac.js is NOT under source root /etc/wb- rules
Apr 13 11:25:06 wirenboard-AGLNKPX3 authpriv.info CRON[3279]: pam_unix(cron:session): session closed for user root
Apr 13 11:25:06 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: [rule info] add your rules to /etc/wb-rules/
Apr 13 11:25:06 wirenboard-AGLNKPX3 user.notice serial: ModbusRTU::ReadRegisterRange(): failed to read 3 holding(s) @ 6 of device modbus:24: Serial pro tocol error: request timed out
Apr 13 11:25:06 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: /usr/share/wb-rules/load_alarms.js is NOT under source root /etc/wb-rules
Apr 13 11:25:06 wirenboard-AGLNKPX3 daemon.info wb-rules[3324]: INFO: all rule files are loaded

Никакие ручные действия не выполнялись.
Учитывая, что Вы разработчик, я думаю, Вам будет несложно смоделировать эту ситуацию на “чистом” контроллере.