UPDATE 31.10.: Amazon Alexa - ioBroker Skill läuft aus ?

[myssv]

Hier ein Auszug vom LOG. Habe die Stationen 3-32 rausgenommen.

Spoiler

2020-04-12 12:02:48.918 - info: rainbird.0 (6526) Got terminate signal TERMINATE_YOURSELF
2020-04-12 12:02:48.920 - info: rainbird.0 (6526) terminating
2020-04-12 12:02:48.920 - info: rainbird.0 (6526) Terminated (START_IMMEDIATELY_AFTER_STOP): Without reason
2020-04-12 12:02:49.438 - info: host.iobroker instance system.adapter.rainbird.0 terminated with code 156 (156)
2020-04-12 12:02:51.430 - info: host.iobroker instance system.adapter.rainbird.0 started with pid 6885
2020-04-12 12:02:52.231 - debug: rainbird.0 (6885) Redis Objects: Use Redis connection: 127.0.0.1:9001
2020-04-12 12:02:52.259 - debug: rainbird.0 (6885) Objects client ready ... initialize now
2020-04-12 12:02:52.262 - debug: rainbird.0 (6885) Objects create System PubSub Client
2020-04-12 12:02:52.263 - debug: rainbird.0 (6885) Objects create User PubSub Client
2020-04-12 12:02:52.263 - debug: rainbird.0 (6885) Objects client initialize lua scripts
2020-04-12 12:02:52.271 - debug: rainbird.0 (6885) Objects connected to redis: 127.0.0.1:9001
2020-04-12 12:02:52.276 - debug: rainbird.0 (6885) objectDB connected
2020-04-12 12:02:52.278 - debug: rainbird.0 (6885) Redis States: Use Redis connection: 127.0.0.1:9000
2020-04-12 12:02:52.282 - debug: rainbird.0 (6885) States create User PubSub Client
2020-04-12 12:02:52.284 - debug: rainbird.0 (6885) States create System PubSub Client
2020-04-12 12:02:52.289 - debug: rainbird.0 (6885) States connected to redis: 127.0.0.1:9000
2020-04-12 12:02:52.290 - debug: rainbird.0 (6885) statesDB connected
2020-04-12 12:02:53.108 - info: rainbird.0 (6885) starting. Version 0.2.0 in /opt/iobroker/node_modules/iobroker.rainbird, node: v10.20.0
2020-04-12 12:02:53.134 - info: rainbird.0 (6885) [START] Starting Rain Bird adapter
2020-04-12 12:02:53.140 - info: rainbird.0 (6885) [INFO] Configured polling interval: 20000
2020-04-12 12:02:53.141 - debug: rainbird.0 (6885) [START] Started Adapter with: 192.168.115.61
2020-04-12 12:02:53.142 - debug: rainbird.0 (6885) Starting state polling
2020-04-12 12:02:53.143 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:02:53.143 - debug: rainbird.0 (6885) Requesting ModelAndVersion
2020-04-12 12:02:53.155 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:02:53.156 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:53.156 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:02:53.156 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:53.156 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:02:53.157 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:53.157 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:02:53.157 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:53.157 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:02:53.158 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:53.158 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:02:53.158 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:53.158 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:02:53.159 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:53.187 - debug: rainbird.0 (6885) stateChange rainbird.0.info.connection {"val":true,"ack":true,"ts":1586685773178,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685773178}
2020-04-12 12:02:53.194 - debug: rainbird.0 (6885) stateChange rainbird.0.device.commands.advanceZone {"val":false,"ack":true,"ts":1586685773188,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586452125330}
2020-04-12 12:02:53.202 - debug: rainbird.0 (6885) stateChange rainbird.0.device.commands.runProgram {"val":null,"ack":true,"ts":1586685773199,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913458324}
2020-04-12 12:02:53.203 - debug: rainbird.0 (6885) stateChange rainbird.0.device.commands.stopIrrigation {"val":false,"ack":true,"ts":1586685773199,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685540928}
2020-04-12 12:02:53.672 - debug: rainbird.0 (6885) Pos 2 to 5 from 8200030209 is 3 (modelID)
2020-04-12 12:02:53.672 - debug: rainbird.0 (6885) Pos 6 to 7 from 8200030209 is 2 (protocolRevisionMajor)
2020-04-12 12:02:53.673 - debug: rainbird.0 (6885) Pos 8 to 9 from 8200030209 is 9 (protocolRevisionMinor)
2020-04-12 12:02:53.673 - debug: rainbird.0 (6885) Cmd ModelAndVersion completed.
2020-04-12 12:02:53.674 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:02:53.674 - debug: rainbird.0 (6885) Requesting SerialNumber
2020-04-12 12:02:53.693 - debug: rainbird.0 (6885) stateChange rainbird.0.device.model {"val":3,"ack":true,"ts":1586685773690,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:02:53.695 - debug: rainbird.0 (6885) stateChange rainbird.0.device.minor {"val":9,"ack":true,"ts":1586685773690,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913458780}
2020-04-12 12:02:53.698 - debug: rainbird.0 (6885) stateChange rainbird.0.device.major {"val":2,"ack":true,"ts":1586685773691,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:02:54.378 - debug: rainbird.0 (6885) Pos 2 to 17 from 850000000000000000 is 0 (serialNumber)
2020-04-12 12:02:54.379 - debug: rainbird.0 (6885) Cmd SerialNumber completed.
2020-04-12 12:02:54.379 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:02:54.379 - debug: rainbird.0 (6885) Requesting CurrentDate
2020-04-12 12:02:54.425 - debug: rainbird.0 (6885) stateChange rainbird.0.device.serial {"val":null,"ack":true,"ts":1586685774423,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913459131}
2020-04-12 12:02:55.115 - debug: rainbird.0 (6885) Pos 2 to 3 from 920C47E4 is 12 (day)
2020-04-12 12:02:55.115 - debug: rainbird.0 (6885) Pos 4 to 4 from 920C47E4 is 4 (month)
2020-04-12 12:02:55.115 - debug: rainbird.0 (6885) Pos 5 to 7 from 920C47E4 is 2020 (year)
2020-04-12 12:02:55.116 - debug: rainbird.0 (6885) Cmd CurrentDate completed.
2020-04-12 12:02:55.116 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:02:55.116 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:55.116 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:02:55.117 - debug: rainbird.0 (6885) Requesting CurrentIrrigationState
2020-04-12 12:02:55.813 - debug: rainbird.0 (6885) Pos 2 to 3 from C801 is 1 (irrigationState)
2020-04-12 12:02:55.813 - debug: rainbird.0 (6885) Cmd CurrentIrrigationState completed.
2020-04-12 12:02:55.814 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:02:55.814 - debug: rainbird.0 (6885) Requesting RainDelayGet
2020-04-12 12:02:55.860 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.active {"val":true,"ack":true,"ts":1586685775858,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586443310166}
2020-04-12 12:02:56.510 - debug: rainbird.0 (6885) Pos 2 to 5 from B60000 is 0 (delaySetting)
2020-04-12 12:02:56.510 - debug: rainbird.0 (6885) Cmd RainDelayGet completed.
2020-04-12 12:02:56.511 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:02:56.511 - debug: rainbird.0 (6885) Requesting AvailableStations
2020-04-12 12:02:56.518 - debug: rainbird.0 (6885) stateChange rainbird.0.device.settings.rainDelay {"val":0,"ack":true,"ts":1586685776515,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460309}
2020-04-12 12:02:57.220 - debug: rainbird.0 (6885) Pos 2 to 3 from 83003F000000 is 0 (pageNumber)
2020-04-12 12:02:57.220 - debug: rainbird.0 (6885) Pos 4 to 11 from 83003F000000 is 1056964608 (setStations)
2020-04-12 12:02:57.221 - debug: rainbird.0 (6885) Cmd AvailableStations completed.
2020-04-12 12:02:57.228 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:02:57.228 - debug: rainbird.0 (6885) Requesting CurrentStationsActive
2020-04-12 12:02:57.250 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.available {"val":true,"ack":true,"ts":1586685777236,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:02:57.250 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.testZone {"val":false,"ack":true,"ts":1586685777236,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586681215470}
2020-04-12 12:02:57.251 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.runZone {"val":null,"ack":true,"ts":1586685777236,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685468500}
2020-04-12 12:02:57.251 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.available {"val":true,"ack":true,"ts":1586685777236,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:02:57.252 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.testZone {"val":false,"ack":true,"ts":1586685777236,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:02:57.252 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.runZone {"val":null,"ack":true,"ts":1586685777237,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586606134728}
2020-04-12 12:02:57.620 - debug: rainbird.0 (6885) Pos 2 to 3 from BF0000000000 is 0 (pageNumber)
2020-04-12 12:02:57.621 - debug: rainbird.0 (6885) Pos 4 to 11 from BF0000000000 is 0 (activeStations)
2020-04-12 12:02:57.621 - debug: rainbird.0 (6885) Cmd CurrentStationsActive completed.
2020-04-12 12:02:57.621 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:02:57.621 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:57.622 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:02:57.622 - debug: rainbird.0 (6885) Requesting CurrentRainSensorState
2020-04-12 12:02:57.957 - debug: rainbird.0 (6885) Pos 2 to 3 from BE00 is 0 (sensorState)
2020-04-12 12:02:57.957 - debug: rainbird.0 (6885) Cmd CurrentRainSensorState completed.
2020-04-12 12:02:57.958 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:02:57.959 - debug: rainbird.0 (6885) Requesting CurrentTime
2020-04-12 12:02:58.006 - debug: rainbird.0 (6885) stateChange rainbird.0.device.sensors.rain {"val":false,"ack":true,"ts":1586685778004,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586585429185}
2020-04-12 12:02:58.368 - debug: rainbird.0 (6885) Pos 2 to 3 from 900C0311 is 12 (hour)
2020-04-12 12:02:58.368 - debug: rainbird.0 (6885) Pos 4 to 5 from 900C0311 is 3 (minute)
2020-04-12 12:02:58.368 - debug: rainbird.0 (6885) Pos 6 to 7 from 900C0311 is 17 (second)
2020-04-12 12:02:58.368 - debug: rainbird.0 (6885) Cmd CurrentTime completed.
2020-04-12 12:02:58.369 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:02:58.369 - debug: rainbird.0 (6885) Requesting CurrentRunTime
2020-04-12 12:02:58.417 - debug: rainbird.0 (6885) stateChange rainbird.0.device.datetime {"val":1586685797000,"ack":true,"ts":1586685778415,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685778415}
2020-04-12 12:02:58.735 - debug: rainbird.0 (6885) Pos 8 to 11 from BB000000000000020000 is 0 (secondsRemaining)
2020-04-12 12:02:58.735 - debug: rainbird.0 (6885) Pos 16 to 17 from BB000000000000020000 is 0 (activeStation)
2020-04-12 12:02:58.735 - debug: rainbird.0 (6885) Pos 22 to 23 from BB000000000000020000 is NaN (running)
2020-04-12 12:02:58.736 - debug: rainbird.0 (6885) Cmd CurrentRunTime completed.
2020-04-12 12:02:58.743 - debug: rainbird.0 (6885) Queue len: 0
2020-04-12 12:02:58.743 - debug: rainbird.0 (6885) Queue processing completed.
2020-04-12 12:02:58.800 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.remaining {"val":0,"ack":true,"ts":1586685778788,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:02:58.800 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.irrigation {"val":false,"ack":true,"ts":1586685778788,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685544481}
2020-04-12 12:02:58.800 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.remaining {"val":0,"ack":true,"ts":1586685778789,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:02:58.800 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.irrigation {"val":false,"ack":true,"ts":1586685778789,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586681243792}
2020-04-12 12:02:58.855 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.station {"val":0,"ack":true,"ts":1586685778798,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685544486}
2020-04-12 12:02:58.856 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.0.remaining {"val":0,"ack":true,"ts":1586685778798,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512744}
2020-04-12 12:02:59.344 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.runZone {"val":0,"ack":false,"ts":1586685779342,"q":0,"from":"system.adapter.web.0","user":"system.user.admin","lc":1586685779342}
2020-04-12 12:02:59.344 - debug: rainbird.0 (6885) id=device.stations.1.runZone
2020-04-12 12:02:59.345 - debug: rainbird.0 (6885) StateChange: ["device.stations.1.runZone",0]
2020-04-12 12:02:59.345 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:02:59.346 - debug: rainbird.0 (6885) Requesting ManuallyRunStation
2020-04-12 12:02:59.712 - debug: rainbird.0 (6885) Pos 2 to 3 from 003904 is 57 (commandEcho)
2020-04-12 12:02:59.712 - debug: rainbird.0 (6885) Pos 4 to 5 from 003904 is 4 (NAKCode)
2020-04-12 12:02:59.713 - warn: rainbird.0 (6885) Status request failed. Requested 01 but got 00: {"type":"NotAcknowledgeResponse","commandEcho":57,"NAKCode":4}
2020-04-12 12:02:59.713 - debug: rainbird.0 (6885) Cmd ManuallyRunStation completed.
2020-04-12 12:02:59.713 - debug: rainbird.0 (6885) Starting state polling
2020-04-12 12:02:59.714 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:02:59.714 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:59.714 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:02:59.714 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:59.714 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:02:59.714 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:59.715 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:02:59.715 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:59.715 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:02:59.715 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:59.715 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:02:59.715 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:59.716 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:02:59.716 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:59.716 - debug: rainbird.0 (6885) Queue len: 8
2020-04-12 12:02:59.716 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:02:59.716 - debug: rainbird.0 (6885) Queue len: 8
2020-04-12 12:02:59.716 - debug: rainbird.0 (6885) Requesting ModelAndVersion
2020-04-12 12:02:59.725 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.runZone {"val":null,"ack":true,"ts":1586685779721,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685779721}
2020-04-12 12:03:00.070 - debug: rainbird.0 (6885) Pos 2 to 5 from 8200030209 is 3 (modelID)
2020-04-12 12:03:00.070 - debug: rainbird.0 (6885) Pos 6 to 7 from 8200030209 is 2 (protocolRevisionMajor)
2020-04-12 12:03:00.070 - debug: rainbird.0 (6885) Pos 8 to 9 from 8200030209 is 9 (protocolRevisionMinor)
2020-04-12 12:03:00.071 - debug: rainbird.0 (6885) Cmd ModelAndVersion completed.
2020-04-12 12:03:00.071 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:03:00.071 - debug: rainbird.0 (6885) Requesting SerialNumber
2020-04-12 12:03:00.077 - debug: rainbird.0 (6885) stateChange rainbird.0.device.model {"val":3,"ack":true,"ts":1586685780075,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:03:00.077 - debug: rainbird.0 (6885) stateChange rainbird.0.device.minor {"val":9,"ack":true,"ts":1586685780075,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913458780}
2020-04-12 12:03:00.078 - debug: rainbird.0 (6885) stateChange rainbird.0.device.major {"val":2,"ack":true,"ts":1586685780075,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:03:00.483 - debug: rainbird.0 (6885) Pos 2 to 17 from 850000000000000000 is 0 (serialNumber)
2020-04-12 12:03:00.483 - debug: rainbird.0 (6885) Cmd SerialNumber completed.
2020-04-12 12:03:00.484 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:00.484 - debug: rainbird.0 (6885) Requesting CurrentDate
2020-04-12 12:03:00.489 - debug: rainbird.0 (6885) stateChange rainbird.0.device.serial {"val":null,"ack":true,"ts":1586685780486,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913459131}
2020-04-12 12:03:00.831 - debug: rainbird.0 (6885) Pos 2 to 3 from 920C47E4 is 12 (day)
2020-04-12 12:03:00.831 - debug: rainbird.0 (6885) Pos 4 to 4 from 920C47E4 is 4 (month)
2020-04-12 12:03:00.831 - debug: rainbird.0 (6885) Pos 5 to 7 from 920C47E4 is 2020 (year)
2020-04-12 12:03:00.832 - debug: rainbird.0 (6885) Cmd CurrentDate completed.
2020-04-12 12:03:00.832 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:00.832 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:00.832 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:00.832 - debug: rainbird.0 (6885) Requesting CurrentIrrigationState
2020-04-12 12:03:01.210 - debug: rainbird.0 (6885) Pos 2 to 3 from C801 is 1 (irrigationState)
2020-04-12 12:03:01.210 - debug: rainbird.0 (6885) Cmd CurrentIrrigationState completed.
2020-04-12 12:03:01.210 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:03:01.211 - debug: rainbird.0 (6885) Requesting RainDelayGet
2020-04-12 12:03:01.217 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.active {"val":true,"ack":true,"ts":1586685781215,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586443310166}
2020-04-12 12:03:01.563 - debug: rainbird.0 (6885) Pos 2 to 5 from B60000 is 0 (delaySetting)
2020-04-12 12:03:01.564 - debug: rainbird.0 (6885) Cmd RainDelayGet completed.
2020-04-12 12:03:01.564 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:03:01.564 - debug: rainbird.0 (6885) Requesting AvailableStations
2020-04-12 12:03:01.569 - debug: rainbird.0 (6885) stateChange rainbird.0.device.settings.rainDelay {"val":0,"ack":true,"ts":1586685781567,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460309}
2020-04-12 12:03:01.924 - debug: rainbird.0 (6885) Pos 2 to 3 from 83003F000000 is 0 (pageNumber)
2020-04-12 12:03:01.924 - debug: rainbird.0 (6885) Pos 4 to 11 from 83003F000000 is 1056964608 (setStations)
2020-04-12 12:03:01.924 - debug: rainbird.0 (6885) Cmd AvailableStations completed.
2020-04-12 12:03:01.930 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:01.930 - debug: rainbird.0 (6885) Requesting CurrentStationsActive
2020-04-12 12:03:01.947 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.available {"val":true,"ack":true,"ts":1586685781933,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:01.948 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.testZone {"val":false,"ack":true,"ts":1586685781934,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586681215470}
2020-04-12 12:03:01.948 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.runZone {"val":null,"ack":true,"ts":1586685781934,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685779721}
2020-04-12 12:03:01.948 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.available {"val":true,"ack":true,"ts":1586685781934,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:01.948 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.testZone {"val":false,"ack":true,"ts":1586685781934,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:01.948 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.runZone {"val":null,"ack":true,"ts":1586685781934,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586606134728}
2020-04-12 12:03:02.324 - debug: rainbird.0 (6885) Pos 2 to 3 from BF0000000000 is 0 (pageNumber)
2020-04-12 12:03:02.324 - debug: rainbird.0 (6885) Pos 4 to 11 from BF0000000000 is 0 (activeStations)
2020-04-12 12:03:02.324 - debug: rainbird.0 (6885) Cmd CurrentStationsActive completed.
2020-04-12 12:03:02.325 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:02.325 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:02.325 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:02.325 - debug: rainbird.0 (6885) Requesting CurrentRainSensorState
2020-04-12 12:03:02.667 - debug: rainbird.0 (6885) Pos 2 to 3 from BE00 is 0 (sensorState)
2020-04-12 12:03:02.667 - debug: rainbird.0 (6885) Cmd CurrentRainSensorState completed.
2020-04-12 12:03:02.668 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:03:02.668 - debug: rainbird.0 (6885) Requesting CurrentTime
2020-04-12 12:03:02.672 - debug: rainbird.0 (6885) stateChange rainbird.0.device.sensors.rain {"val":false,"ack":true,"ts":1586685782670,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586585429185}
2020-04-12 12:03:03.022 - debug: rainbird.0 (6885) Pos 2 to 3 from 900C0316 is 12 (hour)
2020-04-12 12:03:03.022 - debug: rainbird.0 (6885) Pos 4 to 5 from 900C0316 is 3 (minute)
2020-04-12 12:03:03.022 - debug: rainbird.0 (6885) Pos 6 to 7 from 900C0316 is 22 (second)
2020-04-12 12:03:03.022 - debug: rainbird.0 (6885) Cmd CurrentTime completed.
2020-04-12 12:03:03.023 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:03.023 - debug: rainbird.0 (6885) Requesting CurrentRunTime
2020-04-12 12:03:03.065 - debug: rainbird.0 (6885) stateChange rainbird.0.device.datetime {"val":1586685802000,"ack":true,"ts":1586685783062,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685783062}
2020-04-12 12:03:03.390 - debug: rainbird.0 (6885) Pos 8 to 11 from BB000000000000020000 is 0 (secondsRemaining)
2020-04-12 12:03:03.390 - debug: rainbird.0 (6885) Pos 16 to 17 from BB000000000000020000 is 0 (activeStation)
2020-04-12 12:03:03.390 - debug: rainbird.0 (6885) Pos 22 to 23 from BB000000000000020000 is NaN (running)
2020-04-12 12:03:03.390 - debug: rainbird.0 (6885) Cmd CurrentRunTime completed.
2020-04-12 12:03:03.395 - debug: rainbird.0 (6885) Queue len: 0
2020-04-12 12:03:03.395 - debug: rainbird.0 (6885) Queue processing completed.
2020-04-12 12:03:03.556 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.remaining {"val":0,"ack":true,"ts":1586685783418,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:03:03.556 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.irrigation {"val":false,"ack":true,"ts":1586685783419,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685544481}
2020-04-12 12:03:03.557 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.remaining {"val":0,"ack":true,"ts":1586685783419,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:03:03.558 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.irrigation {"val":false,"ack":true,"ts":1586685783419,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586681243792}
2020-04-12 12:03:03.618 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.station {"val":0,"ack":true,"ts":1586685783443,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685544486}
2020-04-12 12:03:03.618 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.0.remaining {"val":0,"ack":true,"ts":1586685783443,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512744}
2020-04-12 12:03:06.164 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.runZone {"val":5,"ack":false,"ts":1586685786163,"q":0,"from":"system.adapter.web.0","user":"system.user.admin","lc":1586685786163}
2020-04-12 12:03:06.165 - debug: rainbird.0 (6885) id=device.stations.2.runZone
2020-04-12 12:03:06.165 - debug: rainbird.0 (6885) StateChange: ["device.stations.2.runZone",5]
2020-04-12 12:03:06.165 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:06.165 - debug: rainbird.0 (6885) Requesting ManuallyRunStation
2020-04-12 12:03:06.515 - debug: rainbird.0 (6885) Pos 2 to 3 from 0139 is 57 (commandEcho)
2020-04-12 12:03:06.516 - debug: rainbird.0 (6885) Cmd ManuallyRunStation completed.
2020-04-12 12:03:06.516 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:06.516 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:06.516 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:06.516 - debug: rainbird.0 (6885) Requesting CurrentStationsActive
2020-04-12 12:03:06.879 - debug: rainbird.0 (6885) Pos 2 to 3 from BF0002000000 is 0 (pageNumber)
2020-04-12 12:03:06.880 - debug: rainbird.0 (6885) Pos 4 to 11 from BF0002000000 is 33554432 (activeStations)
2020-04-12 12:03:06.880 - debug: rainbird.0 (6885) Cmd CurrentStationsActive completed.
2020-04-12 12:03:06.880 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:06.880 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:06.881 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:06.881 - debug: rainbird.0 (6885) Requesting CurrentRunTime
2020-04-12 12:03:07.593 - debug: rainbird.0 (6885) Pos 8 to 11 from BB00000100000202012C is 0 (secondsRemaining)
2020-04-12 12:03:07.594 - debug: rainbird.0 (6885) Pos 16 to 17 from BB00000100000202012C is 1 (activeStation)
2020-04-12 12:03:07.594 - debug: rainbird.0 (6885) Pos 22 to 23 from BB00000100000202012C is NaN (running)
2020-04-12 12:03:07.594 - debug: rainbird.0 (6885) Cmd CurrentRunTime completed.
2020-04-12 12:03:07.594 - debug: rainbird.0 (6885) Starting state polling
2020-04-12 12:03:07.595 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:07.595 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:07.595 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:03:07.595 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:07.595 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:07.595 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:07.596 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:03:07.596 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:07.596 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:03:07.596 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:07.596 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:07.598 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:07.598 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:03:07.598 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:07.598 - debug: rainbird.0 (6885) Queue len: 8
2020-04-12 12:03:07.598 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:07.599 - debug: rainbird.0 (6885) Queue len: 8
2020-04-12 12:03:07.599 - debug: rainbird.0 (6885) Requesting ModelAndVersion
2020-04-12 12:03:07.688 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.runZone {"val":null,"ack":true,"ts":1586685787685,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685787685}
2020-04-12 12:03:08.327 - debug: rainbird.0 (6885) Pos 2 to 5 from 8200030209 is 3 (modelID)
2020-04-12 12:03:08.327 - debug: rainbird.0 (6885) Pos 6 to 7 from 8200030209 is 2 (protocolRevisionMajor)
2020-04-12 12:03:08.327 - debug: rainbird.0 (6885) Pos 8 to 9 from 8200030209 is 9 (protocolRevisionMinor)
2020-04-12 12:03:08.327 - debug: rainbird.0 (6885) Cmd ModelAndVersion completed.
2020-04-12 12:03:08.328 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:03:08.328 - debug: rainbird.0 (6885) Requesting SerialNumber
2020-04-12 12:03:08.336 - debug: rainbird.0 (6885) stateChange rainbird.0.device.model {"val":3,"ack":true,"ts":1586685788332,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:03:08.336 - debug: rainbird.0 (6885) stateChange rainbird.0.device.minor {"val":9,"ack":true,"ts":1586685788332,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913458780}
2020-04-12 12:03:08.337 - debug: rainbird.0 (6885) stateChange rainbird.0.device.major {"val":2,"ack":true,"ts":1586685788333,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:03:09.041 - debug: rainbird.0 (6885) Pos 2 to 17 from 850000000000000000 is 0 (serialNumber)
2020-04-12 12:03:09.041 - debug: rainbird.0 (6885) Cmd SerialNumber completed.
2020-04-12 12:03:09.042 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:09.042 - debug: rainbird.0 (6885) Requesting CurrentDate
2020-04-12 12:03:09.047 - debug: rainbird.0 (6885) stateChange rainbird.0.device.serial {"val":null,"ack":true,"ts":1586685789044,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913459131}
2020-04-12 12:03:09.778 - debug: rainbird.0 (6885) Pos 2 to 3 from 920C47E4 is 12 (day)
2020-04-12 12:03:09.779 - debug: rainbird.0 (6885) Pos 4 to 4 from 920C47E4 is 4 (month)
2020-04-12 12:03:09.779 - debug: rainbird.0 (6885) Pos 5 to 7 from 920C47E4 is 2020 (year)
2020-04-12 12:03:09.779 - debug: rainbird.0 (6885) Cmd CurrentDate completed.
2020-04-12 12:03:09.779 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:09.780 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:09.780 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:09.780 - debug: rainbird.0 (6885) Requesting CurrentIrrigationState
2020-04-12 12:03:10.468 - debug: rainbird.0 (6885) Pos 2 to 3 from C801 is 1 (irrigationState)
2020-04-12 12:03:10.469 - debug: rainbird.0 (6885) Cmd CurrentIrrigationState completed.
2020-04-12 12:03:10.469 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:03:10.469 - debug: rainbird.0 (6885) Requesting RainDelayGet
2020-04-12 12:03:10.474 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.active {"val":true,"ack":true,"ts":1586685790472,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586443310166}
2020-04-12 12:03:11.172 - debug: rainbird.0 (6885) Pos 2 to 5 from B60000 is 0 (delaySetting)
2020-04-12 12:03:11.173 - debug: rainbird.0 (6885) Cmd RainDelayGet completed.
2020-04-12 12:03:11.173 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:03:11.173 - debug: rainbird.0 (6885) Requesting AvailableStations
2020-04-12 12:03:11.177 - debug: rainbird.0 (6885) stateChange rainbird.0.device.settings.rainDelay {"val":0,"ack":true,"ts":1586685791176,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460309}
2020-04-12 12:03:11.884 - debug: rainbird.0 (6885) Pos 2 to 3 from 83003F000000 is 0 (pageNumber)
2020-04-12 12:03:11.885 - debug: rainbird.0 (6885) Pos 4 to 11 from 83003F000000 is 1056964608 (setStations)
2020-04-12 12:03:11.885 - debug: rainbird.0 (6885) Cmd AvailableStations completed.
2020-04-12 12:03:11.889 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:11.889 - debug: rainbird.0 (6885) Requesting CurrentStationsActive
2020-04-12 12:03:11.907 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.available {"val":true,"ack":true,"ts":1586685791894,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:11.907 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.testZone {"val":false,"ack":true,"ts":1586685791895,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586681215470}
2020-04-12 12:03:11.907 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.runZone {"val":null,"ack":true,"ts":1586685791895,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685779721}
2020-04-12 12:03:11.907 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.available {"val":true,"ack":true,"ts":1586685791895,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:11.908 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.testZone {"val":false,"ack":true,"ts":1586685791895,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:11.908 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.runZone {"val":null,"ack":true,"ts":1586685791896,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685787685}
2020-04-12 12:03:12.585 - debug: rainbird.0 (6885) Pos 2 to 3 from BF0002000000 is 0 (pageNumber)
2020-04-12 12:03:12.585 - debug: rainbird.0 (6885) Pos 4 to 11 from BF0002000000 is 33554432 (activeStations)
2020-04-12 12:03:12.585 - debug: rainbird.0 (6885) Cmd CurrentStationsActive completed.
2020-04-12 12:03:12.585 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:12.586 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:12.586 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:12.586 - debug: rainbird.0 (6885) Requesting CurrentRainSensorState
2020-04-12 12:03:12.921 - debug: rainbird.0 (6885) Pos 2 to 3 from BE00 is 0 (sensorState)
2020-04-12 12:03:12.922 - debug: rainbird.0 (6885) Cmd CurrentRainSensorState completed.
2020-04-12 12:03:12.923 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:03:12.923 - debug: rainbird.0 (6885) Requesting CurrentTime
2020-04-12 12:03:12.931 - debug: rainbird.0 (6885) stateChange rainbird.0.device.sensors.rain {"val":false,"ack":true,"ts":1586685792929,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586585429185}
2020-04-12 12:03:13.282 - debug: rainbird.0 (6885) Pos 2 to 3 from 900C0320 is 12 (hour)
2020-04-12 12:03:13.282 - debug: rainbird.0 (6885) Pos 4 to 5 from 900C0320 is 3 (minute)
2020-04-12 12:03:13.282 - debug: rainbird.0 (6885) Pos 6 to 7 from 900C0320 is 32 (second)
2020-04-12 12:03:13.282 - debug: rainbird.0 (6885) Cmd CurrentTime completed.
2020-04-12 12:03:13.283 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:13.283 - debug: rainbird.0 (6885) Requesting CurrentRunTime
2020-04-12 12:03:13.289 - debug: rainbird.0 (6885) stateChange rainbird.0.device.datetime {"val":1586685812000,"ack":true,"ts":1586685793287,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685793287}
2020-04-12 12:03:13.649 - debug: rainbird.0 (6885) Pos 8 to 11 from BB000001000002020126 is 0 (secondsRemaining)
2020-04-12 12:03:13.649 - debug: rainbird.0 (6885) Pos 16 to 17 from BB000001000002020126 is 1 (activeStation)
2020-04-12 12:03:13.650 - debug: rainbird.0 (6885) Pos 22 to 23 from BB000001000002020126 is NaN (running)
2020-04-12 12:03:13.650 - debug: rainbird.0 (6885) Cmd CurrentRunTime completed.
2020-04-12 12:03:13.663 - debug: rainbird.0 (6885) Queue len: 0
2020-04-12 12:03:13.663 - debug: rainbird.0 (6885) Queue processing completed.
2020-04-12 12:03:13.682 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.remaining {"val":0,"ack":true,"ts":1586685793667,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:03:13.683 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.irrigation {"val":false,"ack":true,"ts":1586685793667,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685544481}
2020-04-12 12:03:13.683 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.irrigation {"val":true,"ack":true,"ts":1586685793668,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685793668}
2020-04-12 12:03:13.732 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.station {"val":2,"ack":true,"ts":1586685793677,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685793677}
2020-04-12 12:03:13.733 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.remaining {"val":0,"ack":true,"ts":1586685793677,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:03:27.598 - debug: rainbird.0 (6885) Starting state polling
2020-04-12 12:03:27.599 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:27.599 - debug: rainbird.0 (6885) Requesting ModelAndVersion
2020-04-12 12:03:27.601 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:27.601 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:27.601 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:03:27.601 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:27.601 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:27.602 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:27.602 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:03:27.602 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:27.602 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:03:27.602 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:27.603 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:27.603 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:27.603 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:03:27.603 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:27.945 - debug: rainbird.0 (6885) Pos 2 to 5 from 8200030209 is 3 (modelID)
2020-04-12 12:03:27.947 - debug: rainbird.0 (6885) Pos 6 to 7 from 8200030209 is 2 (protocolRevisionMajor)
2020-04-12 12:03:27.947 - debug: rainbird.0 (6885) Pos 8 to 9 from 8200030209 is 9 (protocolRevisionMinor)
2020-04-12 12:03:27.947 - debug: rainbird.0 (6885) Cmd ModelAndVersion completed.
2020-04-12 12:03:27.948 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:03:27.948 - debug: rainbird.0 (6885) Requesting SerialNumber
2020-04-12 12:03:27.955 - debug: rainbird.0 (6885) stateChange rainbird.0.device.model {"val":3,"ack":true,"ts":1586685807951,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:03:27.956 - debug: rainbird.0 (6885) stateChange rainbird.0.device.minor {"val":9,"ack":true,"ts":1586685807951,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913458780}
2020-04-12 12:03:27.957 - debug: rainbird.0 (6885) stateChange rainbird.0.device.major {"val":2,"ack":true,"ts":1586685807951,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:03:28.311 - debug: rainbird.0 (6885) Pos 2 to 17 from 850000000000000000 is 0 (serialNumber)
2020-04-12 12:03:28.312 - debug: rainbird.0 (6885) Cmd SerialNumber completed.
2020-04-12 12:03:28.312 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:28.312 - debug: rainbird.0 (6885) Requesting CurrentDate
2020-04-12 12:03:28.318 - debug: rainbird.0 (6885) stateChange rainbird.0.device.serial {"val":null,"ack":true,"ts":1586685808315,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913459131}
2020-04-12 12:03:28.695 - debug: rainbird.0 (6885) Pos 2 to 3 from 920C47E4 is 12 (day)
2020-04-12 12:03:28.696 - debug: rainbird.0 (6885) Pos 4 to 4 from 920C47E4 is 4 (month)
2020-04-12 12:03:28.696 - debug: rainbird.0 (6885) Pos 5 to 7 from 920C47E4 is 2020 (year)
2020-04-12 12:03:28.696 - debug: rainbird.0 (6885) Cmd CurrentDate completed.
2020-04-12 12:03:28.696 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:28.697 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:28.697 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:28.697 - debug: rainbird.0 (6885) Requesting CurrentIrrigationState
2020-04-12 12:03:29.035 - debug: rainbird.0 (6885) Pos 2 to 3 from C801 is 1 (irrigationState)
2020-04-12 12:03:29.035 - debug: rainbird.0 (6885) Cmd CurrentIrrigationState completed.
2020-04-12 12:03:29.036 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:03:29.036 - debug: rainbird.0 (6885) Requesting RainDelayGet
2020-04-12 12:03:29.040 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.active {"val":true,"ack":true,"ts":1586685809038,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586443310166}
2020-04-12 12:03:29.389 - debug: rainbird.0 (6885) Pos 2 to 5 from B60000 is 0 (delaySetting)
2020-04-12 12:03:29.389 - debug: rainbird.0 (6885) Cmd RainDelayGet completed.
2020-04-12 12:03:29.389 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:03:29.390 - debug: rainbird.0 (6885) Requesting AvailableStations
2020-04-12 12:03:29.395 - debug: rainbird.0 (6885) stateChange rainbird.0.device.settings.rainDelay {"val":0,"ack":true,"ts":1586685809393,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460309}
2020-04-12 12:03:29.749 - debug: rainbird.0 (6885) Pos 2 to 3 from 83003F000000 is 0 (pageNumber)
2020-04-12 12:03:29.750 - debug: rainbird.0 (6885) Pos 4 to 11 from 83003F000000 is 1056964608 (setStations)
2020-04-12 12:03:29.750 - debug: rainbird.0 (6885) Cmd AvailableStations completed.
2020-04-12 12:03:29.753 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:29.753 - debug: rainbird.0 (6885) Requesting CurrentStationsActive
2020-04-12 12:03:29.763 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.available {"val":true,"ack":true,"ts":1586685809756,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:29.763 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.testZone {"val":false,"ack":true,"ts":1586685809756,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586681215470}
2020-04-12 12:03:29.765 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.runZone {"val":null,"ack":true,"ts":1586685809756,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685779721}
2020-04-12 12:03:29.766 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.available {"val":true,"ack":true,"ts":1586685809756,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:29.773 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.testZone {"val":false,"ack":true,"ts":1586685809756,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:29.773 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.runZone {"val":null,"ack":true,"ts":1586685809756,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685787685}
2020-04-12 12:03:30.150 - debug: rainbird.0 (6885) Pos 2 to 3 from BF0002000000 is 0 (pageNumber)
2020-04-12 12:03:30.150 - debug: rainbird.0 (6885) Pos 4 to 11 from BF0002000000 is 33554432 (activeStations)
2020-04-12 12:03:30.151 - debug: rainbird.0 (6885) Cmd CurrentStationsActive completed.
2020-04-12 12:03:30.151 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:30.151 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:30.151 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:30.151 - debug: rainbird.0 (6885) Requesting CurrentRainSensorState
2020-04-12 12:03:30.486 - debug: rainbird.0 (6885) Pos 2 to 3 from BE00 is 0 (sensorState)
2020-04-12 12:03:30.487 - debug: rainbird.0 (6885) Cmd CurrentRainSensorState completed.
2020-04-12 12:03:30.487 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:03:30.487 - debug: rainbird.0 (6885) Requesting CurrentTime
2020-04-12 12:03:30.493 - debug: rainbird.0 (6885) stateChange rainbird.0.device.sensors.rain {"val":false,"ack":true,"ts":1586685810491,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586585429185}
2020-04-12 12:03:30.857 - debug: rainbird.0 (6885) Pos 2 to 3 from 900C0332 is 12 (hour)
2020-04-12 12:03:30.858 - debug: rainbird.0 (6885) Pos 4 to 5 from 900C0332 is 3 (minute)
2020-04-12 12:03:30.858 - debug: rainbird.0 (6885) Pos 6 to 7 from 900C0332 is 50 (second)
2020-04-12 12:03:30.858 - debug: rainbird.0 (6885) Cmd CurrentTime completed.
2020-04-12 12:03:30.858 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:30.858 - debug: rainbird.0 (6885) Requesting CurrentRunTime
2020-04-12 12:03:30.866 - debug: rainbird.0 (6885) stateChange rainbird.0.device.datetime {"val":1586685830000,"ack":true,"ts":1586685810861,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685810861}
2020-04-12 12:03:31.215 - debug: rainbird.0 (6885) Pos 8 to 11 from BB000001000002020114 is 0 (secondsRemaining)
2020-04-12 12:03:31.215 - debug: rainbird.0 (6885) Pos 16 to 17 from BB000001000002020114 is 1 (activeStation)
2020-04-12 12:03:31.216 - debug: rainbird.0 (6885) Pos 22 to 23 from BB000001000002020114 is NaN (running)
2020-04-12 12:03:31.216 - debug: rainbird.0 (6885) Cmd CurrentRunTime completed.
2020-04-12 12:03:31.227 - debug: rainbird.0 (6885) Queue len: 0
2020-04-12 12:03:31.227 - debug: rainbird.0 (6885) Queue processing completed.
2020-04-12 12:03:31.242 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.remaining {"val":0,"ack":true,"ts":1586685811229,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:03:31.244 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.irrigation {"val":false,"ack":true,"ts":1586685811229,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685544481}
2020-04-12 12:03:31.245 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.irrigation {"val":true,"ack":true,"ts":1586685811229,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685793668}
2020-04-12 12:03:31.325 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.station {"val":2,"ack":true,"ts":1586685811235,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685793677}
2020-04-12 12:03:31.325 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.remaining {"val":0,"ack":true,"ts":1586685811235,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:03:47.604 - debug: rainbird.0 (6885) Starting state polling
2020-04-12 12:03:47.604 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:47.604 - debug: rainbird.0 (6885) Requesting ModelAndVersion
2020-04-12 12:03:47.605 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:47.605 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:47.605 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:03:47.606 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:47.606 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:47.606 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:47.606 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:03:47.606 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:47.606 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:03:47.607 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:47.607 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:47.607 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:47.607 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:03:47.607 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:47.963 - debug: rainbird.0 (6885) Pos 2 to 5 from 8200030209 is 3 (modelID)
2020-04-12 12:03:47.963 - debug: rainbird.0 (6885) Pos 6 to 7 from 8200030209 is 2 (protocolRevisionMajor)
2020-04-12 12:03:47.963 - debug: rainbird.0 (6885) Pos 8 to 9 from 8200030209 is 9 (protocolRevisionMinor)
2020-04-12 12:03:47.963 - debug: rainbird.0 (6885) Cmd ModelAndVersion completed.
2020-04-12 12:03:47.964 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:03:47.964 - debug: rainbird.0 (6885) Requesting SerialNumber
2020-04-12 12:03:47.971 - debug: rainbird.0 (6885) stateChange rainbird.0.device.model {"val":3,"ack":true,"ts":1586685827966,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:03:47.971 - debug: rainbird.0 (6885) stateChange rainbird.0.device.minor {"val":9,"ack":true,"ts":1586685827966,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913458780}
2020-04-12 12:03:47.972 - debug: rainbird.0 (6885) stateChange rainbird.0.device.major {"val":2,"ack":true,"ts":1586685827966,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:03:48.677 - debug: rainbird.0 (6885) Pos 2 to 17 from 850000000000000000 is 0 (serialNumber)
2020-04-12 12:03:48.677 - debug: rainbird.0 (6885) Cmd SerialNumber completed.
2020-04-12 12:03:48.678 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:48.678 - debug: rainbird.0 (6885) Requesting CurrentDate
2020-04-12 12:03:48.814 - debug: rainbird.0 (6885) stateChange rainbird.0.device.serial {"val":null,"ack":true,"ts":1586685828798,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913459131}
2020-04-12 12:03:49.415 - debug: rainbird.0 (6885) Pos 2 to 3 from 920C47E4 is 12 (day)
2020-04-12 12:03:49.415 - debug: rainbird.0 (6885) Pos 4 to 4 from 920C47E4 is 4 (month)
2020-04-12 12:03:49.415 - debug: rainbird.0 (6885) Pos 5 to 7 from 920C47E4 is 2020 (year)
2020-04-12 12:03:49.415 - debug: rainbird.0 (6885) Cmd CurrentDate completed.
2020-04-12 12:03:49.415 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:49.416 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:49.416 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:03:49.416 - debug: rainbird.0 (6885) Requesting CurrentIrrigationState
2020-04-12 12:03:50.105 - debug: rainbird.0 (6885) Pos 2 to 3 from C801 is 1 (irrigationState)
2020-04-12 12:03:50.105 - debug: rainbird.0 (6885) Cmd CurrentIrrigationState completed.
2020-04-12 12:03:50.105 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:03:50.105 - debug: rainbird.0 (6885) Requesting RainDelayGet
2020-04-12 12:03:50.109 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.active {"val":true,"ack":true,"ts":1586685830107,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586443310166}
2020-04-12 12:03:50.816 - debug: rainbird.0 (6885) Pos 2 to 5 from B60000 is 0 (delaySetting)
2020-04-12 12:03:50.817 - debug: rainbird.0 (6885) Cmd RainDelayGet completed.
2020-04-12 12:03:50.817 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:03:50.817 - debug: rainbird.0 (6885) Requesting AvailableStations
2020-04-12 12:03:50.821 - debug: rainbird.0 (6885) stateChange rainbird.0.device.settings.rainDelay {"val":0,"ack":true,"ts":1586685830819,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460309}
2020-04-12 12:03:51.519 - debug: rainbird.0 (6885) Pos 2 to 3 from 83003F000000 is 0 (pageNumber)
2020-04-12 12:03:51.520 - debug: rainbird.0 (6885) Pos 4 to 11 from 83003F000000 is 1056964608 (setStations)
2020-04-12 12:03:51.520 - debug: rainbird.0 (6885) Cmd AvailableStations completed.
2020-04-12 12:03:51.523 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:51.523 - debug: rainbird.0 (6885) Requesting CurrentStationsActive
2020-04-12 12:03:51.533 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.available {"val":true,"ack":true,"ts":1586685831527,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:51.536 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.testZone {"val":false,"ack":true,"ts":1586685831527,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586681215470}
2020-04-12 12:03:51.537 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.runZone {"val":null,"ack":true,"ts":1586685831527,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685779721}
2020-04-12 12:03:51.537 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.available {"val":true,"ack":true,"ts":1586685831527,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:51.537 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.testZone {"val":false,"ack":true,"ts":1586685831527,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:03:51.538 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.runZone {"val":null,"ack":true,"ts":1586685831528,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685787685}
2020-04-12 12:03:52.220 - debug: rainbird.0 (6885) Pos 2 to 3 from BF0002000000 is 0 (pageNumber)
2020-04-12 12:03:52.220 - debug: rainbird.0 (6885) Pos 4 to 11 from BF0002000000 is 33554432 (activeStations)
2020-04-12 12:03:52.221 - debug: rainbird.0 (6885) Cmd CurrentStationsActive completed.
2020-04-12 12:03:52.221 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:52.221 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:03:52.221 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:03:52.221 - debug: rainbird.0 (6885) Requesting CurrentRainSensorState
2020-04-12 12:03:52.907 - debug: rainbird.0 (6885) Pos 2 to 3 from BE00 is 0 (sensorState)
2020-04-12 12:03:52.907 - debug: rainbird.0 (6885) Cmd CurrentRainSensorState completed.
2020-04-12 12:03:52.908 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:03:52.908 - debug: rainbird.0 (6885) Requesting CurrentTime
2020-04-12 12:03:52.914 - debug: rainbird.0 (6885) stateChange rainbird.0.device.sensors.rain {"val":false,"ack":true,"ts":1586685832910,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586585429185}
2020-04-12 12:03:53.619 - debug: rainbird.0 (6885) Pos 2 to 3 from 900C040C is 12 (hour)
2020-04-12 12:03:53.620 - debug: rainbird.0 (6885) Pos 4 to 5 from 900C040C is 4 (minute)
2020-04-12 12:03:53.620 - debug: rainbird.0 (6885) Pos 6 to 7 from 900C040C is 12 (second)
2020-04-12 12:03:53.620 - debug: rainbird.0 (6885) Cmd CurrentTime completed.
2020-04-12 12:03:53.620 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:03:53.620 - debug: rainbird.0 (6885) Requesting CurrentRunTime
2020-04-12 12:03:53.627 - debug: rainbird.0 (6885) stateChange rainbird.0.device.datetime {"val":1586685852000,"ack":true,"ts":1586685833622,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685833622}
2020-04-12 12:03:53.985 - debug: rainbird.0 (6885) Pos 8 to 11 from BB0000010000020200FD is 0 (secondsRemaining)
2020-04-12 12:03:53.986 - debug: rainbird.0 (6885) Pos 16 to 17 from BB0000010000020200FD is 0 (activeStation)
2020-04-12 12:03:53.986 - debug: rainbird.0 (6885) Pos 22 to 23 from BB0000010000020200FD is NaN (running)
2020-04-12 12:03:53.986 - debug: rainbird.0 (6885) Cmd CurrentRunTime completed.
2020-04-12 12:03:53.990 - debug: rainbird.0 (6885) Queue len: 0
2020-04-12 12:03:53.990 - debug: rainbird.0 (6885) Queue processing completed.
2020-04-12 12:03:54.003 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.remaining {"val":0,"ack":true,"ts":1586685833991,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:03:54.003 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.irrigation {"val":false,"ack":true,"ts":1586685833991,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685544481}
2020-04-12 12:03:54.004 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.irrigation {"val":true,"ack":true,"ts":1586685833991,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685793668}
2020-04-12 12:03:54.097 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.station {"val":2,"ack":true,"ts":1586685834002,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685793677}
2020-04-12 12:03:54.098 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.0.remaining {"val":0,"ack":true,"ts":1586685834002,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512744}
2020-04-12 12:04:03.829 - debug: rainbird.0 (6885) stateChange rainbird.0.device.commands.stopIrrigation {"val":true,"ack":false,"ts":1586685843826,"q":0,"from":"system.adapter.web.0","user":"system.user.admin","lc":1586685843826}
2020-04-12 12:04:03.829 - debug: rainbird.0 (6885) id=device.commands.stopIrrigation
2020-04-12 12:04:03.830 - debug: rainbird.0 (6885) StateChange: ["device.commands.stopIrrigation",true]
2020-04-12 12:04:03.830 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:04:03.830 - debug: rainbird.0 (6885) Requesting StopIrrigation
2020-04-12 12:04:04.318 - debug: rainbird.0 (6885) Pos 2 to 3 from 0140 is 64 (commandEcho)
2020-04-12 12:04:04.318 - debug: rainbird.0 (6885) Cmd StopIrrigation completed.
2020-04-12 12:04:04.318 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:04:04.319 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:04.319 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:04:04.319 - debug: rainbird.0 (6885) Requesting CurrentStationsActive
2020-04-12 12:04:05.031 - debug: rainbird.0 (6885) Pos 2 to 3 from BF0000000000 is 0 (pageNumber)
2020-04-12 12:04:05.032 - debug: rainbird.0 (6885) Pos 4 to 11 from BF0000000000 is 0 (activeStations)
2020-04-12 12:04:05.032 - debug: rainbird.0 (6885) Cmd CurrentStationsActive completed.
2020-04-12 12:04:05.032 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:04:05.032 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.032 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:04:05.032 - debug: rainbird.0 (6885) Requesting CurrentRunTime
2020-04-12 12:04:05.746 - debug: rainbird.0 (6885) Pos 8 to 11 from BB000000000000020000 is 0 (secondsRemaining)
2020-04-12 12:04:05.746 - debug: rainbird.0 (6885) Pos 16 to 17 from BB000000000000020000 is 0 (activeStation)
2020-04-12 12:04:05.746 - debug: rainbird.0 (6885) Pos 22 to 23 from BB000000000000020000 is NaN (running)
2020-04-12 12:04:05.747 - debug: rainbird.0 (6885) Cmd CurrentRunTime completed.
2020-04-12 12:04:05.747 - debug: rainbird.0 (6885) Starting state polling
2020-04-12 12:04:05.747 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:04:05.747 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.748 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:04:05.748 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.748 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:04:05.748 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.748 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:04:05.748 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.748 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:04:05.749 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.749 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:04:05.749 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.749 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:04:05.749 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.749 - debug: rainbird.0 (6885) Queue len: 8
2020-04-12 12:04:05.749 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:05.750 - debug: rainbird.0 (6885) Queue len: 8
2020-04-12 12:04:05.750 - debug: rainbird.0 (6885) Requesting ModelAndVersion
2020-04-12 12:04:05.760 - debug: rainbird.0 (6885) stateChange rainbird.0.device.commands.stopIrrigation {"val":false,"ack":true,"ts":1586685845754,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685845754}
2020-04-12 12:04:06.429 - debug: rainbird.0 (6885) Pos 2 to 5 from 8200030209 is 3 (modelID)
2020-04-12 12:04:06.429 - debug: rainbird.0 (6885) Pos 6 to 7 from 8200030209 is 2 (protocolRevisionMajor)
2020-04-12 12:04:06.429 - debug: rainbird.0 (6885) Pos 8 to 9 from 8200030209 is 9 (protocolRevisionMinor)
2020-04-12 12:04:06.430 - debug: rainbird.0 (6885) Cmd ModelAndVersion completed.
2020-04-12 12:04:06.430 - debug: rainbird.0 (6885) Queue len: 7
2020-04-12 12:04:06.430 - debug: rainbird.0 (6885) Requesting SerialNumber
2020-04-12 12:04:06.434 - debug: rainbird.0 (6885) stateChange rainbird.0.device.model {"val":3,"ack":true,"ts":1586685846432,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:04:06.435 - debug: rainbird.0 (6885) stateChange rainbird.0.device.minor {"val":9,"ack":true,"ts":1586685846432,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913458780}
2020-04-12 12:04:06.436 - debug: rainbird.0 (6885) stateChange rainbird.0.device.major {"val":2,"ack":true,"ts":1586685846432,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680507600}
2020-04-12 12:04:07.144 - debug: rainbird.0 (6885) Pos 2 to 17 from 850000000000000000 is 0 (serialNumber)
2020-04-12 12:04:07.144 - debug: rainbird.0 (6885) Cmd SerialNumber completed.
2020-04-12 12:04:07.144 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:04:07.144 - debug: rainbird.0 (6885) Requesting CurrentDate
2020-04-12 12:04:07.148 - debug: rainbird.0 (6885) stateChange rainbird.0.device.serial {"val":null,"ack":true,"ts":1586685847147,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913459131}
2020-04-12 12:04:07.839 - debug: rainbird.0 (6885) Pos 2 to 3 from 920C47E4 is 12 (day)
2020-04-12 12:04:07.839 - debug: rainbird.0 (6885) Pos 4 to 4 from 920C47E4 is 4 (month)
2020-04-12 12:04:07.839 - debug: rainbird.0 (6885) Pos 5 to 7 from 920C47E4 is 2020 (year)
2020-04-12 12:04:07.840 - debug: rainbird.0 (6885) Cmd CurrentDate completed.
2020-04-12 12:04:07.840 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:04:07.840 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:07.840 - debug: rainbird.0 (6885) Queue len: 6
2020-04-12 12:04:07.840 - debug: rainbird.0 (6885) Requesting CurrentIrrigationState
2020-04-12 12:04:08.521 - debug: rainbird.0 (6885) Pos 2 to 3 from C801 is 1 (irrigationState)
2020-04-12 12:04:08.521 - debug: rainbird.0 (6885) Cmd CurrentIrrigationState completed.
2020-04-12 12:04:08.522 - debug: rainbird.0 (6885) Queue len: 5
2020-04-12 12:04:08.522 - debug: rainbird.0 (6885) Requesting RainDelayGet
2020-04-12 12:04:08.526 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.active {"val":true,"ack":true,"ts":1586685848524,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586443310166}
2020-04-12 12:04:08.878 - debug: rainbird.0 (6885) Pos 2 to 5 from B60000 is 0 (delaySetting)
2020-04-12 12:04:08.878 - debug: rainbird.0 (6885) Cmd RainDelayGet completed.
2020-04-12 12:04:08.878 - debug: rainbird.0 (6885) Queue len: 4
2020-04-12 12:04:08.878 - debug: rainbird.0 (6885) Requesting AvailableStations
2020-04-12 12:04:08.886 - debug: rainbird.0 (6885) stateChange rainbird.0.device.settings.rainDelay {"val":0,"ack":true,"ts":1586685848881,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460309}
2020-04-12 12:04:09.236 - debug: rainbird.0 (6885) Pos 2 to 3 from 83003F000000 is 0 (pageNumber)
2020-04-12 12:04:09.236 - debug: rainbird.0 (6885) Pos 4 to 11 from 83003F000000 is 1056964608 (setStations)
2020-04-12 12:04:09.236 - debug: rainbird.0 (6885) Cmd AvailableStations completed.
2020-04-12 12:04:09.239 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:04:09.239 - debug: rainbird.0 (6885) Requesting CurrentStationsActive
2020-04-12 12:04:09.246 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.available {"val":true,"ack":true,"ts":1586685849242,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:04:09.247 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.testZone {"val":false,"ack":true,"ts":1586685849242,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586681215470}
2020-04-12 12:04:09.249 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.runZone {"val":null,"ack":true,"ts":1586685849242,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685779721}
2020-04-12 12:04:09.250 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.available {"val":true,"ack":true,"ts":1586685849242,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:04:09.250 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.testZone {"val":false,"ack":true,"ts":1586685849243,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1582913460730}
2020-04-12 12:04:09.251 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.runZone {"val":null,"ack":true,"ts":1586685849243,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685787685}
2020-04-12 12:04:09.585 - debug: rainbird.0 (6885) Pos 2 to 3 from BF0000000000 is 0 (pageNumber)
2020-04-12 12:04:09.586 - debug: rainbird.0 (6885) Pos 4 to 11 from BF0000000000 is 0 (activeStations)
2020-04-12 12:04:09.586 - debug: rainbird.0 (6885) Cmd CurrentStationsActive completed.
2020-04-12 12:04:09.586 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:04:09.586 - debug: rainbird.0 (6885) Skipping, queue already processing.
2020-04-12 12:04:09.586 - debug: rainbird.0 (6885) Queue len: 3
2020-04-12 12:04:09.586 - debug: rainbird.0 (6885) Requesting CurrentRainSensorState
2020-04-12 12:04:09.922 - debug: rainbird.0 (6885) Pos 2 to 3 from BE00 is 0 (sensorState)
2020-04-12 12:04:09.923 - debug: rainbird.0 (6885) Cmd CurrentRainSensorState completed.
2020-04-12 12:04:09.923 - debug: rainbird.0 (6885) Queue len: 2
2020-04-12 12:04:09.923 - debug: rainbird.0 (6885) Requesting CurrentTime
2020-04-12 12:04:09.928 - debug: rainbird.0 (6885) stateChange rainbird.0.device.sensors.rain {"val":false,"ack":true,"ts":1586685849926,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586585429185}
2020-04-12 12:04:10.286 - debug: rainbird.0 (6885) Pos 2 to 3 from 900C041D is 12 (hour)
2020-04-12 12:04:10.287 - debug: rainbird.0 (6885) Pos 4 to 5 from 900C041D is 4 (minute)
2020-04-12 12:04:10.287 - debug: rainbird.0 (6885) Pos 6 to 7 from 900C041D is 29 (second)
2020-04-12 12:04:10.287 - debug: rainbird.0 (6885) Cmd CurrentTime completed.
2020-04-12 12:04:10.287 - debug: rainbird.0 (6885) Queue len: 1
2020-04-12 12:04:10.287 - debug: rainbird.0 (6885) Requesting CurrentRunTime
2020-04-12 12:04:10.291 - debug: rainbird.0 (6885) stateChange rainbird.0.device.datetime {"val":1586685869000,"ack":true,"ts":1586685850290,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685850290}
2020-04-12 12:04:10.650 - debug: rainbird.0 (6885) Pos 8 to 11 from BB000000000000020000 is 0 (secondsRemaining)
2020-04-12 12:04:10.651 - debug: rainbird.0 (6885) Pos 16 to 17 from BB000000000000020000 is 0 (activeStation)
2020-04-12 12:04:10.651 - debug: rainbird.0 (6885) Pos 22 to 23 from BB000000000000020000 is NaN (running)
2020-04-12 12:04:10.651 - debug: rainbird.0 (6885) Cmd CurrentRunTime completed.
2020-04-12 12:04:10.654 - debug: rainbird.0 (6885) Queue len: 0
2020-04-12 12:04:10.655 - debug: rainbird.0 (6885) Queue processing completed.
2020-04-12 12:04:10.673 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.remaining {"val":0,"ack":true,"ts":1586685850656,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:04:10.673 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.1.irrigation {"val":false,"ack":true,"ts":1586685850656,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685544481}
2020-04-12 12:04:10.674 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.remaining {"val":0,"ack":true,"ts":1586685850656,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512711}
2020-04-12 12:04:10.674 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.2.irrigation {"val":false,"ack":true,"ts":1586685850656,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685850656}
2020-04-12 12:04:10.728 - debug: rainbird.0 (6885) stateChange rainbird.0.device.irrigation.station {"val":0,"ack":true,"ts":1586685850668,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586685850668}
2020-04-12 12:04:10.729 - debug: rainbird.0 (6885) stateChange rainbird.0.device.stations.0.remaining {"val":0,"ack":true,"ts":1586685850668,"q":0,"from":"system.adapter.rainbird.0","user":"system.user.admin","lc":1586680512744}

[StrathCole]

@myssv hm, er zeigt einen Fehler beim manuellen Start der Zone. Oder hattest du mehrfach versucht?

[myssv]

Ich hatte die Zone 2 einmal gestartet, etwas laufen lassen und dann abgebrochen.

[StrathCole]

@myssv oje. Scheinbar liefert dein Steuergerät andere Daten.
Kannst du Mal ein Log machen, in dem du alle Stationen nacheinander mit unterschiedlichen Laufzeiten anschaltest?

[myssv]

Kann ich gerne machen, aber nicht jetzt. Meine Frau ist mit unserem Hund im Garten. Wenn ich da die Bewässerung aktivieren war es mein letztes Osterfest :joy:

Reicht Dir die Anschaltung mit anschließendem Abbruch oder soll ich die Kreise auch durchlaufen lassen?

[StrathCole]

@myssv reicht, wenn es mindestens so lange läuft, bis er einmal gepollt hat, also die Pollingtime aus der Konfig (bei mir 30 Sekunden). dann habe ich für jede Station 2 Werte im Log, das sollte reichen.

[myssv]

Neues Log ist per Mail unterwegs.

[StrathCole]

@myssv Ich habe eine neue Version ins Git geladen, die hoffentlich die korrekten Daten aus deinem Modell ausliest.
Installieren kannst du es via Admin über "Adapter" -> Oben das Symbol mit der Katze (3. von rechts bei mir) -> Andere Quelle -> https://github.com/StrathCole/ioBroker.rainbird

Beim Start sollte im Log dann auch stehen "V0.2.1r34"

[myssv]

@StrathCole sagte in Test Adapter Rain Bird v0.1.x GitHub:

Beim Start sollte im Log dann auch stehen "V0.2.1r34"

Die Version habe ich jetzt, aber es wird leider immer noch keine Restlaufzeit angezeigt. Bleibt weiterhin auf 0 stehen

[StrathCole]

@myssv dann bitte noch mal ein Log, ein Ventil reicht aber.

[myssv]

Mail ist raus

[StrathCole]

@myssv Machst du bitte noch mal ein Update auf r35 via Git und prüfst es erneut?

[myssv]

Jetzt funktioniert es!

Danke dass Du die Feiertage für mich entwickelt hast!!

[myssv]

Kannst Du die Restlaufzeit auch noch in Minuten angeben? Ich stelle ja auch auf Minuten ein und der Sekundenwert wird ja nur alle x-Sekunden aktulisiert (bei mir ca. 20 Sekunden). Da läuft der Zeiger recht abgehackt.

[StrathCole]

@myssv Was würden dir die Minuten bringen? Verstehe es gerade noch nicht ganz.

[myssv]

Ich stelle die Laufzeit in Minuten ein:

Und würde gerne wenn die Bewässerung läuft, den Slider ausblenden und an gleicher Stelle den Restlaufzeit-Slider einblenden:

Das sind aber unterschiedliche Einheiten. Außerdem wird die Restlaufzeit nur alle 20 Sekunden aktualisiert, so dass die Sekunden nur springen und nicht sauber runter zählen.

Rein optische Kosmetik!

[StrathCole]

@myssv Ich mache mir das via Hilfsscript, weil der Controller die Zeit immer in Sekunden liefert. Ich weiß nicht, ob es sinnvoll wäre, das direkt im Adapter zu integrieren, da jeder User die Daten anders verarbeiten will. Was ich noch vorhabe, ist, die Restlaufzeit intern im Adapter feinkörniger runterzuzählen. Unabhängig von der Polling-Time.

In meinem Fall sieht das Skript so aus:

if(existsState('javascript.0.vis.rainbird.remaining_1') === false) {
    createState('vis.rainbird.remaining_1', '', {name: 'Restlaufzeit Station 1', unit: '', type: 'string', role: 'text', def: ''});
}
if(existsState('javascript.0.vis.rainbird.remaining_2') === false) {
    createState('vis.rainbird.remaining_2', '', {name: 'Restlaufzeit Station 2', unit: '', type: 'string', role: 'text', def: ''});
}
if(existsState('javascript.0.vis.rainbird.remaining_3') === false) {
    createState('vis.rainbird.remaining_3', '', {name: 'Restlaufzeit Station 3', unit: '', type: 'string', role: 'text', def: ''});
}
if(existsState('javascript.0.vis.rainbird.remaining_4') === false) {
    createState('vis.rainbird.remaining_4', '', {name: 'Restlaufzeit Station 4', unit: '', type: 'string', role: 'text', def: ''});
}

on({id: ['rainbird.0.device.stations.1.remaining', 'rainbird.0.device.stations.2.remaining', 'rainbird.0.device.stations.3.remaining', 'rainbird.0.device.stations.4.remaining'], change: 'any'}, function(obj) {
    if(obj.state.ack !== true) {
        return;
    }

    let id = 'remaining_1';
    if(obj.id === 'rainbird.0.device.stations.2.remaining') {
        id = 'remaining_2'
    } else if(obj.id === 'rainbird.0.device.stations.3.remaining') {
        id = 'remaining_3'
    } else if(obj.id === 'rainbird.0.device.stations.4.remaining') {
        id = 'remaining_4'
    }

    let minutes = Math.floor(obj.state.val / 60);
    let seconds = obj.state.val - (minutes * 60);

    setState('javascript.0.vis.rainbird.' + id, minutes + ':' + (seconds < 10 ? '0' : '') + seconds, true);
});

[myssv]

OK, das könnte ich mir umbauen.

Auf 6 Stationen habe ich es schon erweitert, aber wie definiere ich die Variablen als Zahlen?

Ich würde dann dort nur die Minuten rein schreiben und könnte dann den Slider auf diesen Datenpunkt aufsetzen und hätte meinen Wunsch erfüllt.

[StrathCole]

@myssv sagte in Test Adapter Rain Bird v0.1.x GitHub:

OK, das könnte ich mir umbauen.

Auf 6 Stationen habe ich es schon erweitert, aber wie definiere ich die Variablen als Zahlen?

Ich würde dann dort nur die Minuten rein schreiben und könnte dann den Slider auf diesen Datenpunkt aufsetzen und hätte meinen Wunsch erfüllt.

also statt
createState('vis.rainbird.remaining_4', '', {name: 'Restlaufzeit Station 4', unit: '', type: 'string', role: 'text', def: ''});
dann
createState('vis.rainbird.remaining_4', 0, {name: 'Restlaufzeit Station 4', unit: 'min', type: 'number', role: 'value', def: 0});

[myssv]

Danke!!

Ist jetzt genauso, wie ich es mir gewünscht habe!! :+1: