Honeywell CH/DHW via RF - evohome, sundial, hometronics, chronotherm

Further investigation of the log shows this

Logger: ramses_rf.gateway
Source: runner.py:188
First occurred: 20:33:50 (1 occurrences)
Last logged: 20:33:50

Failed to send 0006|RQ|01:108199: 0006|RQ|01:108199: Other error

then

Logger: ramses_tx.message
Source: runner.py:188
First occurred: 20:33:43 (48 occurrences)
Last logged: 20:35:30

W --- 18:069148 02:022960 --:------ 2309 001 03 < Payload doesn't match '^0[0-9A-F]{5}$': 03
W --- 18:069148 02:022960 --:------ 2309 001 04 < Payload doesn't match '^0[0-9A-F]{5}$': 04
W --- 18:069148 02:022960 --:------ 2309 001 05 < Payload doesn't match '^0[0-9A-F]{5}$': 05
W --- 18:069148 02:022960 --:------ 2309 001 06 < Payload doesn't match '^0[0-9A-F]{5}$': 06
W --- 18:069148 02:022960 --:------ 2309 001 07 < Payload doesn't match '^0[0-9A-F]{5}$': 07

Followed by

Logger: ramses_rf.entity_base
Source: runner.py:188
First occurred: 20:35:23 (12 occurrences)
Last logged: 20:40:31

No response for task(2309| I|02:022960|05): throttling to 1/6h
No response for task(2309| I|02:022960|06): throttling to 1/6h
No response for task(2309| I|02:022960|07): throttling to 1/6h
No response for task(12B0|RP|01:108199|04): throttling to 1/6h
No response for task(2349|RP|01:108199|07): throttling to 1/6h

and finally

Logger: ramses_rf.entity_base
Source: runner.py:188
First occurred: 20:35:23 (12 occurrences)
Last logged: 20:40:31

No response for task(2309| I|02:022960|05): throttling to 1/6h
No response for task(2309| I|02:022960|06): throttling to 1/6h
No response for task(2309| I|02:022960|07): throttling to 1/6h
No response for task(12B0|RP|01:108199|04): throttling to 1/6h
No response for task(2349|RP|01:108199|07): throttling to 1/6h

Hey guys,

Iā€™ve been getting similar errors.

Logger: ramses_rf.entity_base
Source: runner.py:188
First occurred: 09:45:37 (14 occurrences)
Last logged: 20:50:57

No response for task(12B0|RP|01:131527|06): throttling to 1/6h
No response for task(12B0|RP|01:131527|0A): throttling to 1/6h
No response for task(12B0|RP|01:131527|07): throttling to 1/6h
No response for task(2349|RP|01:131527|08): throttling to 1/6h
No response for task(0008|RP|13:105896): throttling to 1/6h

But I also have errors in home assistant

Logger: homeassistant
Source: core.py:691
First occurred: 09:45:03 (240 occurrences)
Last logged: 21:09:33

Error doing job: Exception in callback _run_async_call_action(<HomeAssistant RUNNING>, <Job call_lat...527_03=heat>>>) at /usr/src/homeassistant/homeassistant/helpers/event.py:1450
Error doing job: Exception in callback _run_async_call_action(<HomeAssistant RUNNING>, <Job call_lat...527_02=heat>>>) at /usr/src/homeassistant/homeassistant/helpers/event.py:1450
Error doing job: Exception in callback _run_async_call_action(<HomeAssistant RUNNING>, <Job call_lat...527_0a=heat>>>) at /usr/src/homeassistant/homeassistant/helpers/event.py:1450
Error doing job: Exception in callback _run_async_call_action(<HomeAssistant RUNNING>, <Job call_lat...527_08=heat>>>) at /usr/src/homeassistant/homeassistant/helpers/event.py:1450
Error doing job: Exception in callback _run_async_call_action(<HomeAssistant RUNNING>, <Job call_lat...527_04=heat>>>) at /usr/src/homeassistant/homeassistant/helpers/event.py:1450
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/src/homeassistant/homeassistant/helpers/event.py", line 1454, in _run_async_call_action
    hass.async_run_hass_job(job, time_tracker_utcnow())
  File "/usr/src/homeassistant/homeassistant/core.py", line 691, in async_run_hass_job
    hassjob.target(*args)
TypeError: Entity.async_write_ha_state() takes 1 positional argument but 2 were given

I canā€™t set the temp on all of my radiators anymore, it seems to randomly set it on a couple and the others wonā€™t be set. Or when the schedule is due to turn off those Radiators some stay on. Iā€™ve also had it on a few occasions where the temp of a zone is set to 25, even though Iā€™ve not set that anywhere. Something odd is going on. Iā€™m running the latest version.

AFAIK, this service call hasnā€™t been renamed.

You can use either ramses_cc.send_command or remote.send_command, the latter simply has a more targeted UI.

This has been fixed.

1 Like

thatā€™s odd, because issuing the command using remote.send_command failed with unknown error. Only thing I did was switch the commands and that worked, just a bit iffy though if the fan actually respondsā€¦

just checked using a manual service call and using the remote.send and it fails, spitting out an error. Also tried setting repeats and holding, but the same error continues:

Logger: homeassistant.helpers.script.websocket_api_script
Source: helpers/script.py:476
First occurred: 22 januari 2024 om 12:18:18 (7 occurrences)
Last logged: 01:29:46

websocket_api script: Error executing script. Unexpected error for call_service at pos 1: {'hold_secs': 0.0}
websocket_api script: Error executing script. Unexpected error for call_service at pos 1: {'hold_secs': 0.2}
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 476, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 713, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 675, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2149, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2186, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 272, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 882, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 952, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/config/custom_components/ramses_cc/remote.py", line 212, in async_send_command
    assert not kwargs, kwargs  # TODO: remove me
    ^^^^^^^^^^^^^^^^^^^^^^^^^

type or paste code here

There is a reason why holding isnā€™t available in ramses_cc.send_command: it is not supported.

You have not provided the entire tracelog, in fact, you truncated just before the most helpful bit.

Have a look in the packet log, or at least post the relevant section here.

Sorry about that, it was what was in the logbook. Where can I find the bit youā€™d want to see?

Hi David, I do have a real RF-15 so that clarifies a lot.

Iam not able to impersonate the remote so I tried binding a virtual remote but it did not work either:

configuration.yaml

ramses_cc:
  packet_log:
    file_name: packet.log
    rotate_backups: 28
  serial_port: /dev/serial/by-id/usb-SparkFun_evofw3_atmega32u4-if00
  restore_cache:
    restore_schema: false
    restore_state: false
  known_list:
    # 29:177904:
    37:123456:
      class: REM
      faked: true
      _note: Orcon 15RF remote
      commands:
        away: " I --- 29:177904 29:226830 --:------ 22F1 003 000004"
        low: " I --- 29:177904 29:226830 --:------ 22F1 003 000104"
        medium: " I --- 29:177904 29:226830 --:------ 22F1 003 000204"
        high: " I --- 29:177904 29:226830 --:------ 22F1 003 000304"
        auto: " I --- 29:177904 29:226830 --:------ 22F1 003 000404"
        timer_15mins: " I --- 29:177904 29:226830 --:------ 22F3 007 00020F03040000"
        timer_30mins: " I --- 29:177904 29:226830 --:------ 22F3 007 00021E03040000"
        timer_60mins: " I --- 29:177904 29:226830 --:------ 22F3 007 00023C03040000"
  ramses_rf:
    enforce_known_list: true

Then I put the MVS-15 in pairing mode and execute this call:

`service: ramses_cc.bind_device
data:
  device_id: 37:123456
  offer:
    "22F1":
    "22F3":
    "10E0":
  device_info: " I --- 37:123456 63:262142 --:------ 10E0 038 000001C894030167FFFFFFFFFFFF1B0807E4564D492D313557534A3533000000000000000000"`

The log:

ramses_rf.exceptions.BindingFlowFailed: 37:123456: SuppSendOfferWaitForAccept: Failed to transition to <class 'ramses_rf.binding_fsm.SuppIsReadyToSendConfirm'>: expected message not received after 3.0 secs

The packet.log:

2024-01-23T11:06:44.124015 074  I --- --:------ --:------ 29:226830 042F 006 000081008000
2024-01-23T11:06:44.202015 074  I --- 29:226830 63:262142 --:------ 10E0 029 000001C8260D0467FFFFFFFFFFFFFFFFFFFF564D432D31355250303100
2024-01-23T11:06:44.277223 074  I --- 29:226830 --:------ 29:226830 31D9 003 000004
2024-01-23T11:06:45.024342 073  I --- 29:226830 --:------ 29:226830 31D9 003 000004
2024-01-23T11:06:50.009288 079  I --- 29:226830 --:------ 29:226830 31D9 003 000004
2024-01-23T11:06:54.337816 089  I --- --:------ --:------ 12:251039 1030 016 01C80137C9010FCA0196CB010FCC0101
2024-01-23T11:06:55.331565 089  I --- --:------ --:------ 12:251039 1030 016 01C80137C9010FCA0196CB010FCC0101
2024-01-23T11:06:56.331638 089  I --- --:------ --:------ 12:251039 1030 016 01C80137C9010FCA0196CB010FCC0101
2024-01-23T11:06:57.326647 090  I --- --:------ --:------ 12:251039 313F 009 0038020A2B170107E8
2024-01-23T11:07:09.004457 076  I --- 29:226830 --:------ 29:226830 31D9 003 000004
2024-01-23T11:07:09.134436 075  I --- 29:226830 --:------ 29:226830 31D9 003 000004
2024-01-23T11:07:09.258490 075  I --- 29:226830 --:------ 29:226830 31D9 003 000004
2024-01-23T11:07:48.326745 ...  I --- 37:123456 --:------ 37:123456 1FC9 024 0022F195E2400022F395E2406710E095E240001FC995E240
2024-01-23T11:07:48.375064 000  I --- 18:003601 63:262142 --:------ 7FFF 023 0011018D35CA526731464339204936333A323632313432
2024-01-23T11:07:48.400075 000  I --- 37:123456 --:------ 37:123456 1FC9 024 0022F195E2400022F395E2406710E095E240001FC995E240
2024-01-23T11:07:48.423068 000  I --- 37:123456 --:------ 37:123456 1FC9 024 0022F195E2400022F395E2406710E095E240001FC995E240
2024-01-23T11:07:48.434046 075  W --- 29:226830 37:123456 --:------ 1FC9 006 0031D977760E
2024-01-23T11:07:49.858131 076  W --- 29:226830 37:123456 --:------ 1FC9 006 0031D977760E
2024-01-23T11:07:51.336336 076  W --- 29:226830 37:123456 --:------ 1FC9 006 0031D977760E
2024-01-23T11:07:52.808556 075  W --- 29:226830 37:123456 --:------ 1FC9 006 0031D977760E
2024-01-23T11:08:27.252949 090  I --- 32:098347 29:233787 --:------ 31E0 008 0000000001001E00
2024-01-23T11:09:06.420815 048  I --- 29:183243 --:------ 29:183243 1298 003 00034F
2024-01-23T11:09:49.327122 088  I --- --:------ --:------ 12:251039 0008 002 0000
2024-01-23T11:09:50.321045 088  I --- --:------ --:------ 12:251039 0008 002 0000
2024-01-23T11:09:51.321281 089  I --- --:------ --:------ 12:251039 0008 002 0000
2024-01-23T11:10:32.481390 093  I --- 13:183647 --:------ 13:183647 3EF0 003 0000FF
2024-01-23T11:11:03.711744 091  I --- 32:098347 --:------ 32:098347 1298 003 0001A0
2024-01-23T11:11:14.902926 077  I --- 29:226841 --:------ 29:226841 31D9 003 000003
2024-01-23T11:11:15.029917 077  I --- 29:226841 --:------ 29:226841 31D9 003 000003
2024-01-23T11:11:23.153339 079  I --- 29:183317 --:------ 29:183317 1298 003 00028B
2024-01-23T11:12:06.548377 074  I --- 29:226830 --:------ 29:226830 31D9 003 000004
2024-01-23T11:12:06.672371 075  I --- 29:226830 --:------ 29:226830 31D9 003 000004
2024-01-23T11:12:06.795398 074  I --- 29:226830 --:------ 29:226830 31D9 003 000004

Is there something Iam doing wrong here?

Has the sensor.01_198631_00_temperature entity been depreciated? these are showing as Unavailable on all of mine (think this may be since the 18th Jan when I went to 0.31.2. the data is in the Climate entity.

Additionally the 07: is still showing available, although due to frequency of update its quite unstable and goes to unavailable a lot this causes me a number of issues with running a reliable card. As you mentioned before this seems to be quite slow at updating as a sensor (even the controller is slow to get this data updates.

My issue is with most cards/mods state filters are what drive them. Most cards do not support attributes of an entity for driving these mods. is there a way to drive a separate Temperature feed from the 01 controller for this or force poll the 07 sensors before I build my own option?

Note other sensors and systems still seem fine on 0.31.3 BTW

one thing that seems to clears up these random unavailable entities/attributes between versions is to do a restart with restore_cache/state false. Yes, it might take a while for everything to come back up, but for me it usually sorts everything out. Donā€™t forget to comment out the restore_* lines again afterwards - a restart on the same version maintains cache/state correctly, at least for me. I know David stated that cache/state should work between versions, but not always the case on my system.

No.

These devices are notorious for this. But ramses_rf should take this into account.

Have a look in homeassistant.log.

All your RSSIs are borderline (75-90) - the reception is very weak.

Sent 3x I|1FC9 - the FAN heard, 'cause it replied with 4x W, but the remote timed out:

BindingFlowFailed: 37:123456: SuppSendOfferWaitForAccept: Failed to transition to SuppIsReadyToSendConfirm: expected message not received after 3.0 secs

Iā€™ll have a think.

Re. OpenTherm sensors. Iā€™ve run 0.30.9 for over 36 hours and getting solid data from my OpenTherm sensors which I canā€™t seem to achieve in 0.31.2 or 0.31.3. Iā€™ve messaged you a 24 hour packet log and Iā€™ll do another long run on 0.31.3 and send a log for a comparable period.

During this time I had good data from all my OpenTherm sensors as detailed in my previous post apart from occasional 1 minute long dropouts on binary_sensor.10_064873_fault_present and sensor.10_064873_value .

Iā€™ve been looking mostly at sensor.10_064873_boiler_output_temp and sensor.10_064873_ch_water_pressure because I have an external sensor that I can compare with the former and Iā€™m particularly interested in the latter.

Ah! I have seen the issue here, I have changed the code from:

        if hold_seconds is not None:
            raise TypeError("hold_seconds is not supported")

ā€¦ to:

        if hold_secs is not None:
            raise TypeError("hold_secs is not supported")

You still canā€™t use hold feature, but at least you get a useful error message.

Hi David

As before, as soon as I switch from 0.30.9 to 0.31.3 several OpenTherm sensors go unavailable as detailed previously. I will message you a full 24 hour packet log from 0.31.3 for comparison as soon as I have it.

In the meantime Iā€™ve been looking at the logs for any obvious differences. Iā€™ve been using

cat ramses_cc_packet.log| grep ' 3220 005 ....12'

which I believe will extract all messages with the Opentherm message code 3220 and 0x12 in the 3rd byte of the payload - i.e CH water pressure.

Under 0.30.9 Iā€™m seeing matching Request and Response packets from the SSM-D2 18:* to the OTB 10:*. Under 0.31.3 the Requests from the SSM-D2 18:* seem to go unanswered but I donā€™t know if Iā€™m interpreting this correctly. Iā€™ve made no other configuration / system changes apart from changing ramses_cc from 0.30.9 to 0.31.3.

A couple of samples ā€œgreppedā€ from the logs:

This is 0.30.9:

2024-01-23T23:47:33.390726 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0000120000
2024-01-23T23:47:33.419734 067 RP --- 10:064873 18:072981 --:------ 3220 005 00C0120161
2024-01-23T23:47:36.534126 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-23T23:47:36.561151 067 RP --- 10:064873 01:216136 --:------ 3220 005 00C0120161
2024-01-23T23:52:39.197695 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0000120000
2024-01-23T23:52:39.213718 066 RP --- 10:064873 18:072981 --:------ 3220 005 00C012015E
2024-01-23T23:52:44.382036 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-23T23:52:44.414024 067 RP --- 10:064873 01:216136 --:------ 3220 005 00C0120161
2024-01-23T23:57:47.552150 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0000120000
2024-01-23T23:57:47.570187 067 RP --- 10:064873 18:072981 --:------ 3220 005 00C012015E
2024-01-23T23:57:48.228857 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-23T23:57:48.257862 068 RP --- 10:064873 01:216136 --:------ 3220 005 00C012015E

ā€¦ and this is 0.31.3:

2024-01-24T13:43:34.149999 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0000120000
2024-01-24T13:43:37.207175 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0000120000
2024-01-24T13:43:37.323184 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-24T13:43:37.351206 066 RP --- 10:064873 01:216136 --:------ 3220 005 0040120159
2024-01-24T13:48:39.169743 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-24T13:48:39.195719 066 RP --- 10:064873 01:216136 --:------ 3220 005 0040120159
2024-01-24T13:53:41.016618 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-24T13:53:41.040585 067 RP --- 10:064873 01:216136 --:------ 3220 005 00C0120157
2024-01-24T13:58:42.863704 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-24T13:58:42.880787 067 RP --- 10:064873 01:216136 --:------ 3220 005 00C0120157
2024-01-24T14:03:44.710245 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-24T14:03:44.738261 066 RP --- 10:064873 01:216136 --:------ 3220 005 00C0120157
2024-01-24T14:08:46.557387 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-24T14:08:46.578400 066 RP --- 10:064873 01:216136 --:------ 3220 005 00C0120157
2024-01-24T14:13:49.226020 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0000120000
2024-01-24T14:13:52.264584 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0000120000
2024-01-24T14:13:52.405048 050 RQ --- 01:216136 10:064873 --:------ 3220 005 0000120000
2024-01-24T14:13:52.422966 066 RP --- 10:064873 01:216136 --:------ 3220 005 00C0120157

If I look at a different sensor thatā€™s working consistently between both versions, such as 0x01 in byte 3 (CH set point) then Iā€™m seeing consistent log results between the two versions.

0.30.9:

2024-01-23T23:28:42.793393 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-23T23:28:42.810395 068 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00
2024-01-23T23:33:58.127173 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-23T23:33:58.146130 067 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00
2024-01-23T23:38:59.717938 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-23T23:38:59.740953 067 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00
2024-01-23T23:43:59.765332 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-23T23:43:59.784279 067 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00
2024-01-23T23:49:05.019261 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-23T23:49:05.038228 067 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00

ā€¦and 0.31.3:

2024-01-24T08:35:54.693186 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-24T08:35:54.711098 066 RP --- 10:064873 18:072981 --:------ 3220 005 00C0011F33
2024-01-24T08:40:54.735908 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-24T08:40:54.754939 067 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00
2024-01-24T08:45:55.815684 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-24T08:45:55.834661 066 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00
2024-01-24T08:50:55.859425 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-24T08:50:55.884406 067 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00
2024-01-24T08:55:55.910177 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-24T08:55:55.925239 066 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00
2024-01-24T09:00:56.353838 000 RQ --- 18:072981 10:064873 --:------ 3220 005 0080010000
2024-01-24T09:00:56.371842 063 RP --- 10:064873 18:072981 --:------ 3220 005 0040010A00

Upgraded to 0.31.3 from 0.30.9 and all dashboards and automations are working as as before
One worth mentioning, which was also present on 0.31.2 too was the Gateway Status - 18_135685_status showing as Problem after the upgrade and as soon as this is rolled back to .30.9 it shows as OK
image

Sorted - fix will be in 0.30.4.

If I understand you correctlyā€¦

Simply create a template sensor using the attr youā€™re interested in, them drive your mod off that.

Perhaps you could be more specific? Yaml?