Closed marcusb closed 9 months ago
~Additional info: I have only been able to trigger this issue when a load is connected to the device. With load connected, it typically triggers within minutes of power-cycle.~
~If no load is connected (ie unplug the lightbulb) the device works correctly as far as I can tell.~
Edit: forget it, I just triggered it without load, although it took a little longer (a couple of hours). As before, only power cycle restores it.
This is unlikely to be entirely a hardware problem, given that the devices are widely sold at Costco and presumably work well with the Tuya app. Also some users are reporting that ESPHome does not suffer from this issue.
Just found the related issue in ESPHOME and a fix. Also an alleged patch for Tasmota.
Compile Tasmota with enabling Tuya MCU v2. Place in your user_config_override.h
#define USE_TUYA_MCU_V2
This implementation has changes which tries to fix Dimmer Issues, but It breaks other Tuya stuff.
There is no active maintainer for the Tuya implementation in Tasmota.
After fixing a compilation error (https://github.com/arendst/Tasmota/pull/20272) and changing some defines, I was able to make the Tuya MCU v2 module work, but it seems a little flaky.
It seemed to work for one of the dimmers, but needed a few manual switch toggles before it remote commands would have any effect. It reacts correctly to manual presses though.
The second dimmer registers the Tuya heartbeats but prints a timeout message every couple of seconds, and generally doesn't react to commands from Tasmota.
00:01:25.986 TYA: Protocol timeout state 1 -> 0
@btsimonh in case you are interested
@marcusb - thankyou. the V2 is meant to observe the published protocol 'better' than the original send and pray approach. For my dimmer, I had almost exactly what you initially reported - by not observing aspects of the protocol, the original tuya implementation caused the MCU to crash/become unresponsive, usually caused by external control (Node-Red or Alexa), recovery only by power cycle (not convenient when in the wall....).
The V2 thing represented literally months of work, gigabytes of logging, and hundreds of builds. But despite requests, the only people who helped with testing had the same dimmer as me (the only tuya mcu based device I have), so it's little tested on other tuya devices.
You can enable (by defines?) a large amount of debug. Unfortunately the code is complex, and hence could hide a few anomolies which might affect your mileage with it. I'm not sure why it would perform differently for two of the same type of dimmer? Possibly suspect the unit itself. (I've abandoned using the touch switches on my wall units, because they just don't wotrk reliably once inside a metal wallbox!) br, Simon
This issue has been automatically marked as stale because it hasn't any activity in last few weeks. It will be closed if no further activity occurs. Thank you for your contributions.
This issue was automatically closed because of being stale. Feel free to open a new one if you still experience this problem.
@btsimonh Thanks for the additional context. I've enabled additional logging. The different behavior I was seeing turns out not to depend on the unit, but on how it's set up. When I have the dimmer in a lab setup on my desk, the v2 code seems fairly stable (though I can occasionally trigger a bad state). But when I wire the same unit into the wallbox, it breaks very easily. I can sometimes cycle power at the breaker and get it to work for a little while, but the MCU usually stops responding within minutes.
Here is a log from triggering an update from the web UI when it works correctly:
2024-02-27T23:21:52.707924-05:00 dimmer5-6129 ESP-TYA: setchan
2024-02-27T23:21:52.709655-05:00 dimmer5-6129 ESP-TYA: DP2 des v set (0xe8030000,4)
2024-02-27T23:21:52.711432-05:00 dimmer5-6129 ESP-TYA: dp2 to 1000 req
2024-02-27T23:21:52.713288-05:00 dimmer5-6129 ESP-TYA: DP2 T2 m0 d1000 s1 r0
2024-02-27T23:21:52.715374-05:00 dimmer5-6129 ESP-TYA: DP1 T1 m0x0 d0x0 s0 r1
2024-02-27T23:21:52.726320-05:00 dimmer5-6129 ESP-TYA: DP1 des v set (0x1,1)
2024-02-27T23:21:52.728115-05:00 dimmer5-6129 ESP-TYA: dp1 to 1 req
2024-02-27T23:21:52.729990-05:00 dimmer5-6129 ESP-TYA: DP2 T2 m0 d1000 s1 r0
2024-02-27T23:21:52.735211-05:00 dimmer5-6129 ESP-TYA: DP1 T1 m0x0 d0x1 s1 r1
2024-02-27T23:21:52.740341-05:00 dimmer5-6129 ESP-TYA: post rpower1 v1 dp1 s0 d0
2024-02-27T23:21:52.790810-05:00 dimmer5-6129 ESP-MQT: stat/dimmer5/RESULT = {"POWER":"ON"}
2024-02-27T23:21:52.794764-05:00 dimmer5-6129 ESP-MQT: stat/dimmer5/POWER = ON
2024-02-27T23:21:52.795529-05:00 dimmer5-6129 ESP-T: >"55aa0006000501010001010e"
2024-02-27T23:21:52.803778-05:00 dimmer5-6129 ESP-TYA: 11->12-130/129
2024-02-27T23:21:52.820207-05:00 dimmer5-6129 ESP-TYA: 12->11-130/130
2024-02-27T23:21:52.820360-05:00 dimmer5-6129 ESP-{"TuyaReceived": {"Data":"55AA03070005010100010112","Cmnd":7,"CmndData":"0101000101","DpType1Id1":1,"1":{"DpId":1,"DpIdType":1,"DpIdData":"01"}}}
2024-02-27T23:21:52.822030-05:00 dimmer5-6129 ESP-TYA: DP2 T2 m0 d1000 s1 r0
2024-02-27T23:21:52.823866-05:00 dimmer5-6129 ESP-TYA: DP1 T1 m0x1 d0x1 s0 r1
2024-02-27T23:21:52.825729-05:00 dimmer5-6129 ESP-T: fn11 Relay1-->MOn TOn
2024-02-27T23:21:53.547697-05:00 dimmer5-6129 ESP-CFG: Saved to flash at F8, Count 343, Bytes 4096
2024-02-27T23:21:54.714667-05:00 dimmer5-6129 ESP-TYA: DimDelay0->0
2024-02-27T23:21:58.232045-05:00 dimmer5-6129 ESP-TYA: 11->13-130/130
2024-02-27T23:21:58.334321-05:00 dimmer5-6129 ESP-T: >"55aa00000000ff"
2024-02-27T23:21:58.340578-05:00 dimmer5-6129 ESP-TYA: 13->14-131/130
And here is a working update when pressing the dimmer button:
2024-02-27T23:25:29.913694-05:00 dimmer5-6129 ESP-{"TuyaReceived": {"Data":"55AA03070005010100010011","Cmnd":7,"CmndData":"0101000100","DpType1Id1":0,"1":{"DpId":1,"DpIdType":1,"DpIdData":"00"}}}
2024-02-27T23:25:29.913694-05:00 dimmer5-6129 ESP-TYA: DP2 T2 m0 d1000 s1 r0
2024-02-27T23:25:29.915129-05:00 dimmer5-6129 ESP-TYA: DP1 T1 m0x0 d0x1 s0 r1
2024-02-27T23:25:29.917068-05:00 dimmer5-6129 ESP-T: fn11 Relay1-->MOff TOn
2024-02-27T23:25:29.919019-05:00 dimmer5-6129 ESP-SRC: Switch
2024-02-27T23:25:29.920779-05:00 dimmer5-6129 ESP-TYA: setchan disbl SRC_SWITCH
2024-02-27T23:25:29.928678-05:00 dimmer5-6129 ESP-TYA: rpower0 v0 dp1 ignored s4 d0
2024-02-27T23:25:29.955630-05:00 dimmer5-6129 ESP-MQT: stat/dimmer5/RESULT = {"POWER":"OFF"}
2024-02-27T23:25:29.957437-05:00 dimmer5-6129 ESP-MQT: stat/dimmer5/POWER = OFF
2024-02-27T23:25:30.551920-05:00 dimmer5-6129 ESP-CFG: Saved to flash at F5, Count 346, Bytes 4096
2024-02-27T23:25:31.815720-05:00 dimmer5-6129 ESP-TYA: DimDelay0->0
In the broken state, updating from the web UI produces:
2024-02-27T23:44:40.828282-05:00 dimmer5-6129 ESP-TYA: Protocol timeout state 1 -> 0
2024-02-27T23:44:40.831249-05:00 dimmer5-6129 ESP-T: >"55aa00000000ff"
2024-02-27T23:44:40.831642-05:00 dimmer5-6129 ESP-TYA: 0->1-10/0
2024-02-27T23:44:42.290658-05:00 dimmer5-6129 ESP-SRC: WebGui from 172.16.1.10
2024-02-27T23:44:42.291430-05:00 dimmer5-6129 ESP-TYA: setchan
2024-02-27T23:44:42.291561-05:00 dimmer5-6129 ESP-TYA: DP2 des v set (0xe8030000,4)
2024-02-27T23:44:42.291704-05:00 dimmer5-6129 ESP-TYA: dp2 to 1000 req
2024-02-27T23:44:42.291926-05:00 dimmer5-6129 ESP-TYA: DP2 T2 m0 d1000 s1 r0
2024-02-27T23:44:42.292886-05:00 dimmer5-6129 ESP-TYA: DP1 T1 m0x0 d0x0 s1 r0
2024-02-27T23:44:42.303087-05:00 dimmer5-6129 ESP-TYA: DP1 des v set (0x1,1)
2024-02-27T23:44:42.305902-05:00 dimmer5-6129 ESP-TYA: dp1 to 1 req
2024-02-27T23:44:42.307111-05:00 dimmer5-6129 ESP-TYA: DP2 T2 m0 d1000 s1 r0
2024-02-27T23:44:42.313024-05:00 dimmer5-6129 ESP-TYA: DP1 T1 m0x0 d0x1 s1 r0
2024-02-27T23:44:42.316827-05:00 dimmer5-6129 ESP-TYA: post rpower1 v1 dp1 s0 d0
2024-02-27T23:44:42.353353-05:00 dimmer5-6129 ESP-MQT: stat/dimmer5/RESULT = {"POWER":"ON"}
2024-02-27T23:44:42.354542-05:00 dimmer5-6129 ESP-MQT: stat/dimmer5/POWER = ON
2024-02-27T23:44:43.341734-05:00 dimmer5-6129 ESP-CFG: Saved to flash at F9, Count 358, Bytes 4096
2024-02-27T23:44:43.859342-05:00 dimmer5-6129 ESP-TYA: Protocol timeout state 1 -> 0
2024-02-27T23:44:43.861112-05:00 dimmer5-6129 ESP-T: >"55aa00000000ff"
2024-02-27T23:44:43.862837-05:00 dimmer5-6129 ESP-TYA: 0->1-11/0
2024-02-27T23:44:46.829034-05:00 dimmer5-6129 ESP-TYA: Protocol timeout state 1 -> 0
2024-02-27T23:44:46.829034-05:00 dimmer5-6129 ESP-T: >"55aa00000000ff"
2024-02-27T23:44:46.830468-05:00 dimmer5-6129 ESP-TYA: 0->1-12/0
2024-02-27T23:44:49.842186-05:00 dimmer5-6129 ESP-TYA: Protocol timeout state 1 -> 0
2024-02-27T23:44:49.843319-05:00 dimmer5-6129 ESP-T: >"55aa00000000ff"
2024-02-27T23:44:49.845092-05:00 dimmer5-6129 ESP-TYA: 0->1-13/0
2024-02-27T23:44:52.855673-05:00 dimmer5-6129 ESP-TYA: Protocol timeout state 1 -> 0
2024-02-27T23:44:52.860399-05:00 dimmer5-6129 ESP-T: >"55aa00000000ff"
2024-02-27T23:44:52.860399-05:00 dimmer5-6129 ESP-TYA: 0->1-14/0
2024-02-27T23:44:55.857862-05:00 dimmer5-6129 ESP-TYA: Protocol timeout state 1 -> 0
2024-02-27T23:44:55.859589-05:00 dimmer5-6129 ESP-T: >"55aa00000000ff"
Some more information, it's slowly getting more clear:
The dimmer does not reliably report all DPs in response to TUYA_CMD_QUERY_STATE
("Query DP status"). It sometimes reports only DP2 (the dimmer channel), sometimes both DP1 and DP2, in separate messages. It appears to report DPs that have had changes applied since last report (ie after toggling). As a result, the driver cannot reliably enumerate all DPs.
The v2 driver has logic to skip sending commands to DPs that it hasn't seen reports for (dp->rxed
flag). Because of the above, Tasmota isn't able to toggle the switch unless the physical button has been pressed at least once, causing the device to report the DP state.
As a workaround, I removed the above logic (checking dp->rxed
), so now I'm able to control the device remotely immediately after boot. No ill effects so far.
The software usually crashes within hours, after which it reboots and emits this:
2024-02-29T02:04:50.305198-05:00 dimmer5-6129 ESP-MQT: tele/dimmer5/INFO3 = {"Info3":{"RestartReason":{"Exception":29,"Reason":"Exception","EPC":["4000df64","00000000","00000000"],"EXCVADDR":"00000000","DEPC":"00000000"},"BootCount":103}}
After that, it's stuck in this bad state, where it is unable to receive any comms from the MCU. The only way to break out of it is to cycle the power at the breaker.
This is looking better and better. The crashes were due to a memory leak similar to https://github.com/arendst/Tasmota/issues/16061, and could be dealt with by removing the DHCP option 42 from the DHCP server and reverting to the default NTP configuration. The device appears a lot more stable now.
PROBLEM DESCRIPTION
I have the Feit Electric Smart Dimmer. As noted in some other forums, users have observed issues with the TuyaMCU communication breaking down intermittently.
The result is that remote control of the dimmer (via web interface) does not work. State changes are reflected in the web UI, but the physical device is not affected. However I can make manual changes to the device, both switch on/off and dimmer control, and those changes are reflected in the web UI. It appears as if the TuyaMCU commands can be received but are not transmitted to the MCU. There are no TuyaMCU heartbeat responses.
It is often possible to restore functionality by a power cycle (not just rebooting), but it tends to break again quickly. I have tested this with 2 different devices, with same results.
REQUESTED INFORMATION
Make sure your have performed every step and checked the applicable boxes before submitting your issue. Thank you!
Backlog Template; Module; GPIO 255
:00:09:03.363 CMD: Grp 0, Cmd 'BACKLOG', Idx 1, Len 26, Pld -99, Data 'Template; Module; GPIO 255' 00:09:03.413 SRC: Backlog 00:09:03.415 CMD: Grp 0, Cmd 'TEMPLATE', Idx 1, Len 0, Pld -99, Data '' 00:09:03.421 MQT: stat/dimmer4/RESULT = {"NAME":"Feit DIM/WIFI","GPIO":[0,2272,0,2304,0,0,0,0,0,0,0,0,0,0],"FLAG":0,"BASE":54} 00:09:03.630 SRC: Backlog 00:09:03.633 CMD: Grp 0, Cmd 'MODULE', Idx 1, Len 0, Pld -99, Data '' 00:09:03.637 MQT: stat/dimmer4/RESULT = {"Module":{"0":"Feit DIM/WIFI"}} 00:09:03.882 SRC: Backlog 00:09:03.885 CMD: Grp 0, Cmd 'GPIO', Idx 1, Len 3, Pld 255, Data '255' 00:09:03.894 MQT: stat/dimmer4/RESULT = {"GPIO0":{"0":"None"},"GPIO1":{"2272":"Tuya Tx"},"GPIO2":{"0":"None"},"GPIO3":{"2304":"Tuya Rx"},"GPIO4":{"0":"None"},"GPIO5":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"0":"None"},"GPIO14":{"0":"None"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"},"GPIO17":{"0":"None"}}
Status 0
:00:09:49.643 CMD: Grp 0, Cmd 'STATUS', Idx 1, Len 1, Pld 0, Data '0' 00:09:49.650 MQT: stat/dimmer4/STATUS = {"Status":{"Module":0,"DeviceName":"dimmer4","FriendlyName":["dimmer4"],"Topic":"dimmer4","ButtonTopic":"0","Power":0,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0,"StatusRetain":0}} 00:09:49.658 MQT: stat/dimmer4/STATUS1 = {"StatusPRM":{"Baudrate":9600,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota/","RestartReason":"Software/System restart","Uptime":"0T00:09:50","StartupUTC":"","Sleep":50,"CfgHolder":4617,"BootCount":22,"BCResetTime":"1970-01-01T00:00:00","SaveCount":90,"SaveAddress":"F7000"}} 00:09:49.666 MQT: stat/dimmer4/STATUS2 = {"StatusFWR":{"Version":"13.3.0.1(tasmota)","BuildDateTime":"2023-12-18T13:04:29","Boot":31,"Core":"2_7_4_9","SDK":"2.2.2-dev(38a443e)","CpuFrequency":80,"Hardware":"ESP8285N08","CR":"303/699"}} 00:09:49.672 MQT: stat/dimmer4/STATUS3 = {"StatusLOG":{"SerialLog":0,"WebLog":3,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["IoT",""],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C80001000600003C5A0A192800000000","00000280","00006000","00004000","00000000"]}} 00:09:49.685 MQT: stat/dimmer4/STATUS4 = {"StatusMEM":{"ProgramSize":638,"Free":364,"Heap":19,"ProgramFlashSize":1024,"FlashSize":1024,"FlashChipId":"144051","FlashFrequency":40,"FlashMode":"DOUT","Features":["0809","8F9AC787","04368001","000000CF","010013C0","C000F981","00004004","00001000","54000020","00000080","00000000"],"Drivers":"1,2,3,4,5,6,7,8,9,10,12,16,18,19,20,21,22,24,26,27,29,30,35,37,45,62,68","Sensors":"1,2,3,4,5,6","I2CDriver":"7"}} 00:09:49.694 MQT: stat/dimmer4/STATUS5 = {"StatusNET":{"Hostname":"dimmer4-4655","IPAddress":"[redacted]","Gateway":"[redacted]","Subnetmask":"255.255.255.0","DNSServer1":"[redacted]","DNSServer2":"0.0.0.0","Mac":"[redacted]","Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":17.0}} 00:09:49.702 MQT: stat/dimmer4/STATUS6 = {"StatusMQT":{"MqttHost":"[redacted]","MqttPort":1883,"MqttClientMask":"dimmer4","MqttClient":"dimmer4","MqttUser":"[redacted]","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":4}} 00:09:49.710 MQT: stat/dimmer4/STATUS7 = {"StatusTIM":{"UTC":"1970-01-01T00:09:49","Local":"1970-01-01T00:09:49","StartDST":"1970-01-01T00:00:00","EndDST":"1970-01-01T00:00:00","Timezone":"+00:00","Sunrise":"20:13","Sunset":"05:47"}} 00:09:49.716 MQT: stat/dimmer4/STATUS10 = {"StatusSNS":{"Time":"1970-01-01T00:09:49"}} 00:09:49.723 MQT: stat/dimmer4/STATUS11 = {"StatusSTS":{"Time":"1970-01-01T00:09:49","Uptime":"0T00:09:50","UptimeSec":590,"Heap":19,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":134,"MqttCount":1,"POWER":"OFF","Dimmer":100,"Fade":"OFF","Speed":1,"LedTable":"ON","Wifi":{"AP":1,"SSId":"[redacted]","BSSId":"[redacted]","Channel":6,"Mode":"11n","RSSI":80,"Signal":-60,"LinkCount":1,"Downtime":"0T00:00:03"}}}
TO REPRODUCE
EXPECTED BEHAVIOUR
Remote control keeps working at all times.
SCREENSHOTS
If applicable, add screenshots to help explain your problem.
ADDITIONAL CONTEXT
Add any other context about the problem here.
(Please, remember to close the issue when the problem has been addressed)