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

[myssv]

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

Es gibt jetzt einen neuen Datenpunkt mit der Restlaufzeit.

Hey super!

Sorry, wenn ich frage: Wie komme ich an die neue Version? Mir wird im ioBroker kein Update angeboten.

[StrathCole]

@myssv entweder aus dem latest Repository in iOBroker oder direkt aus dem GitHub.

Im latest ist die neue Version bereits drin.

[myssv]

OK, nach einem Refresh hat er es gefunden.

Aber der Wert bleibt bei mir auf 0

[StrathCole]

@myssv welches Steuergerät hast du? kannst du den Adapter mal auf debug stellen und die logausgabe per PN schicken?

[myssv]

@StrathCole Ich habe einen ESP-RZXe

Log kommt gleich.

[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.