When the WeMo emulation feature is enabled, the web ui is almost frozen. #5505

wongnam · 2019-03-21T04:39:50Z

BUG DESCRIPTION

When the WeMo emulation feature is enabled, the web ui is almost frozen, the console shows that the network connection has been interrupted continuously.

Read the Contributing Guide and Policy and the Code of Conduct
Searched the problem in issues (https://github.com/arendst/Sonoff-Tasmota/issues)
Searched the problem in the wiki (https://github.com/arendst/Sonoff-Tasmota/wiki/Troubleshooting)
Searched the problem in the forum (https://groups.google.com/d/forum/sonoffusers)
Searched the problem in the chat (https://discord.gg/Ks2Kzd4)
Device used (i.e. Sonoff Basic) : Sonoff Basic, Sonoff TH, Wemos D1
Tasmota binary firmware version number used : pre-compiled latest sonoff.bin version 6.5.0
Development IDE - Compiler / Upload tools used : esptool
Provide the output of command status 0 :

STATUS 0 OUTPUT HERE:
00:00:00 Project sonoff Sonoff Version 6.5.0(release-sonoff)-2_3_0
00:00:00 WIF: Connecting to AP1 iot-2 in mode 11N as sonoff-4359...
00:00:04 WIF: Connected
00:00:04 HTP: Web server active on sonoff-4359 with IP address 192.168.12.140
00:00:04 UPP: Multicast (re)joined
00:00:05 MQT: Attempting connection...
00:00:05 MQT: Connected
00:00:05 MQT: tele/sonoff/LWT = Online (retained)
00:00:05 MQT: cmnd/sonoff/POWER = 
00:00:05 MQT: tele/sonoff/INFO1 = {"Module":"Sonoff Basic","Version":"6.5.0(release-sonoff)","FallbackTopic":"cmnd/DVES_797107_fb/","GroupTopic":"sonoffs"}
00:00:05 MQT: tele/sonoff/INFO2 = {"WebServerMode":"Admin","Hostname":"sonoff-4359","IPAddress":"192.168.12.140"}
00:00:05 MQT: tele/sonoff/INFO3 = {"RestartReason":"External System"}
00:00:05 MQT: stat/sonoff/RESULT = {"POWER":"OFF"}
00:00:05 MQT: stat/sonoff/POWER = OFF
00:00:06 UPP: Multicast (re)joined
05:15:37 RSL: tele/sonoff/STATE = {"Time":"2019-03-21T05:15:32","Uptime":"0T00:00:14","Vcc":2.691,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":60,"LinkCount":1,"Downtime":"0T00:00:04"}}
05:16:07 MQT: Attempting connection...
05:16:07 MQT: Connected
05:16:07 MQT: tele/sonoff/LWT = Online (retained)
05:16:07 MQT: cmnd/sonoff/POWER = 
05:16:08 UPP: Multicast (re)joined
05:16:26 MQT: Attempting connection...
05:16:26 MQT: Connected
05:16:26 MQT: tele/sonoff/LWT = Online (retained)
05:16:26 MQT: cmnd/sonoff/POWER = 
05:16:27 UPP: Multicast (re)joined
05:16:37 CMD: status 0
05:16:37 MQT: stat/sonoff/STATUS = {"Status":{"Module":1,"FriendlyName":["Sonoff"],"Topic":"sonoff","ButtonTopic":"0","Power":0,"PowerOnState":3,"LedState":1,"SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0}}
05:16:37 MQT: stat/sonoff/STATUS1 = {"StatusPRM":{"Baudrate":115200,"GroupTopic":"sonoffs","OtaUrl":"http://thehackbox.org/tasmota/release/sonoff.bin","RestartReason":"External System","Uptime":"0T00:01:19","StartupUTC":"2019-03-21T04:15:18","Sleep":50,"CfgHolder":4617,"BootCount":6,"SaveCount":21,"SaveAddress":"F7000"}}
05:16:37 MQT: stat/sonoff/STATUS2 = {"StatusFWR":{"Version":"6.5.0(release-sonoff)","BuildDateTime":"2019-03-19T12:24:10","Boot":31,"Core":"2_3_0","SDK":"1.5.3(aec24ac9)"}}
05:16:37 MQT: stat/sonoff/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["iot-2",""],"TelePeriod":300,"Resolution":"55A180C0","SetOption":["00008009","280500000100000000000000000000000000","00000000"]}}
05:16:37 MQT: stat/sonoff/STATUS4 = {"StatusMEM":{"ProgramSize":507,"Free":496,"Heap":14,"ProgramFlashSize":1024,"FlashSize":4096,"FlashChipId":"1640C8","FlashMode":3,"Features":["00000809","0FDAE394","000783A0","23B617CE","00003BC0"]}}
05:16:37 MQT: stat/sonoff/STATUS5 = {"StatusNET":{"Hostname":"sonoff-4359","IPAddress":"192.168.12.140","Gateway":"192.168.12.1","Subnetmask":"255.255.255.0","DNSServer":"210.245.31.220","Mac":"60:01:94:79:71:07","Webserver":2,"WifiConfig":4}}
05:16:37 MQT: stat/sonoff/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.12.155","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_797107","MqttUser":"admin","MqttCount":3,"MAX_PACKET_SIZE":1000,"KEEPALIVE":15}}
05:16:37 MQT: stat/sonoff/STATUS7 = {"StatusTIM":{"UTC":"Thu Mar 21 04:16:37 2019","Local":"Thu Mar 21 05:16:37 2019","StartDST":"Sun Mar 31 02:00:00 2019","EndDST":"Sun Oct 27 03:00:00 2019","Timezone":"+01:00","Sunrise":"06:51","Sunset":"19:03"}}
05:16:37 MQT: stat/sonoff/STATUS10 = {"StatusSNS":{"Time":"2019-03-21T05:16:37"}}
05:16:37 MQT: stat/sonoff/STATUS11 = {"StatusSTS":{"Time":"2019-03-21T05:16:37","Uptime":"0T00:01:19","Vcc":2.687,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":66,"LinkCount":1,"Downtime":"0T00:00:04"}}}
05:16:57 MQT: Attempting connection...
05:16:57 MQT: Connected
05:16:57 MQT: tele/sonoff/LWT = Online (retained)
05:16:58 MQT: cmnd/sonoff/POWER = 
05:16:58 UPP: Multicast (re)joined

Provide the output of console when you experience your issue if apply :
05:16:59 CMD: weblog 4
05:16:59 MQT: stat/sonoff/RESULT = {"WebLog":4}
05:16:59 CFG: Saved to flash at F6, Count 22, Bytes 3584
05:17:16 UPP: Multicast disabled
05:17:16 MQT: Attempting connection...
05:17:16 MQT: Connected
05:17:16 MQT: tele/sonoff/LWT = Online (retained)
05:17:16 MQT: cmnd/sonoff/POWER =
05:17:16 MQT: Subscribe to cmnd/sonoff/#
05:17:16 MQT: Subscribe to cmnd/sonoffs/#
05:17:16 MQT: Subscribe to cmnd/DVES_797107_fb/#
05:17:17 UPP: Multicast (re)joined
05:17:47 WIF: Checking connection...
05:17:47 WIF: Connected
05:17:47 UPP: Multicast disabled
05:17:47 MQT: Attempting connection...
05:17:47 MQT: Connected
05:17:47 MQT: tele/sonoff/LWT = Online (retained)
05:17:47 MQT: cmnd/sonoff/POWER =
05:17:47 MQT: Subscribe to cmnd/sonoff/#
05:17:47 MQT: Subscribe to cmnd/sonoffs/#
05:17:47 MQT: Subscribe to cmnd/DVES_797107_fb/#
05:17:48 UPP: Multicast (re)joined
05:18:07 UPP: Multicast disabled
05:18:07 MQT: Attempting connection...
05:18:07 MQT: Connected
05:18:07 MQT: tele/sonoff/LWT = Online (retained)
05:18:07 MQT: cmnd/sonoff/POWER =
05:18:07 MQT: Subscribe to cmnd/sonoff/#
05:18:07 MQT: Subscribe to cmnd/sonoffs/#
05:18:07 MQT: Subscribe to cmnd/DVES_797107_fb/#
05:18:08 UPP: Multicast (re)joined
05:18:22 WIF: Checking connection...
05:18:22 WIF: Connected
05:18:38 UPP: Multicast disabled
05:18:38 MQT: Attempting connection...
05:18:38 MQT: Connected
05:18:38 MQT: tele/sonoff/LWT = Online (retained)
05:18:38 MQT: cmnd/sonoff/POWER =
05:18:38 MQT: Subscribe to cmnd/sonoff/#
05:18:38 MQT: Subscribe to cmnd/sonoffs/#
05:18:38 MQT: Subscribe to cmnd/DVES_797107_fb/#
05:18:39 UPP: Multicast (re)joined

TO REPRODUCE

Just flash the Sonoff.bin to Sonoff Basic using esptool.
Reset configuration in 192.168.4.1
connect it to wifi
connect to mqtt server
every thing will work fine
turn on WeMo
return web ui -> Web ui will be lag and near frozen.

(Please, remember to close the issue when the problem has been addressed)

The text was updated successfully, but these errors were encountered:

wongnam · 2019-03-21T09:41:31Z

Sometimes i got EXCEPTION info as below: FYI.
00:00:06 MQT: tele/wemos/INFO3 = {"RestartReason":"Fatal exception:29 flag:2 (EXCEPTION) epc1:0x4000e1b2 epc2:0x00000000 epc3:0x00000000 excvaddr:0x00000000 depc:0x00000000"}
and SerialLog 4:

10:35:23 MQT: Attempting connection...
10:35:23 MQT: Connected
10:35:23 MQT: tele/wemos/LWT = Online (retained)
10:35:23 MQT: cmnd/wemos/POWER =
10:35:24 UPP: Multicast (re)joined
10:35:43 MQT: Attempting connection...
10:35:44 MQT: Connected
10:35:44 MQT: tele/wemos/LWT = Online (retained)
10:35:44 MQT: cmnd/wemos/POWER =
10:35:44 MQT: tele/wemos/STATE = {"Time":"2019-03-21T10:35:44","Uptime":"0T00:09:22","Vcc":2.684,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":1615,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":58,"LinkCount":1,"Downtime":"0T00:00:04"}}
10:35:44 UPP: Multicast (re)joined
10:35:54 MQT: tele/wemos/STATE = {"Time":"2019-03-21T10:35:54","Uptime":"0T00:09:32","Vcc":2.684,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":56,"LinkCount":1,"Downtime":"0T00:00:04"}}

Exception (29):
epc1=0x4000e1b2 epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000000 depc=0x00000000

ctx: sys
sp: 3ffffd70 end: 3fffffb0 offset: 01a0

>>>stack>>>
3fffff10:  24568cca 000002f4 3ffeeb40 401004f4
3fffff20:  3ffeec40 3ffefaa0 3ffeeb40 40107cdc
3fffff30:  00000007 00000007 00000000 4023ed0e
3fffff40:  40106024 0b5ae3c7 4023f1ce 00000008
3fffff50:  3ffefaa0 3ffeebf4 4023f27b 3ffeebf4
3fffff60:  3ffefaa0 0b5ae3c7 3ffefaa0 60000600
3fffff70:  40250955 3ffeebf4 3ffefaa0 24565647
3fffff80:  4025099a 3fffdab0 00000000 3fffdcb0
3fffff90:  3ffefab0 00000000 40000f65 3fffdab0
3fffffa0:  40000f49 0000561b 3fffdab0 40000f49
<<<stack<<<

 ets Jan  8 2013,rst cause:2, boot mode:(3,7)

load 0x4010f000, len 1384, room 16
tail 8
chksum 0x2d
csum 0x2d
v60000608
~ld

00:00:00 SRC: Restart
00:00:00 Project sonoff WEMOS D1 Version 6.5.0(release-sonoff)-2_3_0
00:00:00 WIF: Checking connection...
00:00:00 WIF: Attempting connection...
00:00:00 WIF: Patch issue 2186
00:00:00 WIF: Connecting to AP1 iot-2 in mode 11N as wemos-4359...
00:00:01 WIF: Checking connection...
00:00:01 WIF: Attempting connection...
00:00:02 WIF: Checking connection...
00:00:02 WIF: Attempting connection...
00:00:03 WIF: Checking connection...
00:00:03 WIF: Attempting connection...
00:00:04 WIF: Checking connection...
00:00:04 WIF: Connected
00:00:04 HTP: Web server active on wemos-4359 with IP address 192.168.12.140
00:00:04 UPP: Multicast (re)joined
00:00:05 UPP: Multicast disabled
00:00:05 MQT: Attempting connection...
00:00:05 MQT: Connected
00:00:05 MQT: tele/wemos/LWT = Online (retained)
00:00:05 MQT: cmnd/wemos/POWER =
00:00:05 MQT: Subscribe to cmnd/wemos/#
00:00:05 MQT: Subscribe to cmnd/sonoffs/#
00:00:05 MQT: Subscribe to cmnd/DVES_797107_fb/#
00:00:05 MQT: tele/wemos/INFO1 = {"Module":"Generic","Version":"6.5.0(release-sonoff)","FallbackTopic":"cmnd/DVES_797107_fb/","GroupTopic":"sonoffs"}
00:00:06 MQT: tele/wemos/INFO2 = {"WebServerMode":"Admin","Hostname":"wemos-4359","IPAddress":"192.168.12.140"}
00:00:06 MQT: tele/wemos/INFO3 = {"RestartReason":"Fatal exception:29 flag:2 (EXCEPTION) epc1:0x4000e1b2 epc2:0x00000000 epc3:0x00000000 excvaddr:0x00000000 depc:0x00000000"}
00:00:06 MQT: stat/wemos/RESULT = {"POWER":"OFF"}
00:00:06 MQT: stat/wemos/POWER = OFF
00:00:06 UPP: Multicast (re)joined
00:00:07 APP: (UTC) Thu Mar 21 09:36:39 2019, (DST) Sun Mar 31 02:00:00 2019, (STD) Sun Oct 27 03:00:00 2019
10:36:42 APP: Boot Count 15
10:36:42 CFG: Saved to flash at F8, Count 36, Bytes 3584
10:36:46 MQT: tele/wemos/STATE = {"Time":"2019-03-21T10:36:46","Uptime":"0T00:00:14","Vcc":2.707,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":58,"LinkCount":1,"Downtime":"0T00:00:04"}}
10:37:00 MQT: tele/wemos/STATE = {"Time":"2019-03-21T10:37:00","Uptime":"0T00:00:28","Vcc":2.706,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":56,"LinkCount":1,"Downtime":"0T00:00:04"}}
10:37:01 WIF: Checking connection...
10:37:01 WIF: Connected
10:37:11 MQT: tele/wemos/STATE = {"Time":"2019-03-21T10:37:10","Uptime":"0T00:00:38","Vcc":2.708,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":54,"LinkCount":1,"Downtime":"0T00:00:04"}}
10:37:25 MQT: tele/wemos/STATE = {"Time":"2019-03-21T10:37:25","Uptime":"0T00:00:53","Vcc":2.686,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":61,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":56,"LinkCount":1,"Downtime":"0T00:00:04"}}
10:37:26 WIF: Checking connection...
10:37:26 WIF: Connected

Jason2866 · 2019-03-21T11:11:07Z

Have you tried Core 2.4.2 too? http://thehackbox.org/tasmota/release/020402/sonoff.bin

wongnam · 2019-03-21T11:39:46Z

Have you tried Core 2.4.2 too? http://thehackbox.org/tasmota/release/020402/sonoff.bin

Yes, i've try 2.4.2, event 2.5.0 have the same symptom. if i uncheck the WeMo emulation then it will go back to normal.

Jason2866 · 2019-03-21T12:34:26Z

Strange, loaded 6.5.0.1 with Arduino stage and SDK 2.2.1 and enabled Belkin on a wemos mini configured as Sonoff Basic. It is up and running since 5 hours. Not a single reconnect and device is responsive as always. Gonna try precompiled release 6.5.0 (core 2.4.2). Will report...
EDIT: OTA went smooth. Release 6.5.0 (core 2.4.2) works without any issue too

Jason2866 · 2019-03-21T12:45:14Z

Please try flashing device with esptool.py. Before flashing erase whole flash with erase_flash
See https://github.com/arendst/Sonoff-Tasmota/wiki/Esptool#erase-firmware

wongnam · 2019-03-21T13:01:47Z

yes, i usually use this tool as mentioned on above template. i don't know if it has any wrong, please correct me. thanks.

C:\Users\Wong Nam\Downloads\Sonoff_Backup\esptool>esptool.py --port COM4 erase_flash
esptool.py v2.1
Connecting....
Detecting chip type... ESP8266
Chip is ESP8266
Uploading stub...
Running stub...
Stub running...
Erasing flash (this may take a while)...
Chip erase completed successfully in 1.8s
Hard resetting...

C:\Users\Wong Nam\Downloads\Sonoff_Backup\esptool>esptool.py --port COM4 write_flash -fs 1MB -fm dout 0x0 sonoff.bin
esptool.py v2.1
Connecting....
Detecting chip type... ESP8266
Chip is ESP8266
Uploading stub...
Running stub...
Stub running...
Configuring flash size...
Compressed 537520 bytes to 367915...
Wrote 537520 bytes (367915 compressed) at 0x00000000 in 32.4 seconds (effective 132.7 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting...

C:\Users\Wong Nam\Downloads\Sonoff_Backup\esptool>

Jason2866 · 2019-03-21T13:10:59Z

Device still fails?

wongnam · 2019-03-21T13:12:15Z

Device still fails?

Sorry. Yes, it's still the same issue.

Jason2866 · 2019-03-21T13:35:14Z

I have no idea left. I cant reproduce this error.

Jason2866 · 2019-03-21T13:39:41Z

Reconnection (wifi) issues appear if power supply is bad.
Most wemos minis have a bad 3.3v reg and sonoff basic are batches with bad power supply too.
But Sonoff TH? Do you have NodeMCU you can try?

Jason2866 · 2019-03-21T14:12:56Z

@wongnam Can you ping the device and upload the results?
Is this working http://thehackbox.org/tasmota/archive/20190309-170231-8a43cfb-sonoff.bin

wongnam · 2019-03-21T14:30:25Z

@Jason2866 i tried 20190309-170231-8a43cfb-sonoff.bin that it boot loops with Fatal exception.

00:00:00 Project sonoff Sonoff Version 6.4.1.21(8a43cfb-sonoff)-2_4_2
00:00:00 WIF: Connecting to AP1 iot-2 in mode 11N as sonoff-2372...
00:00:04 WIF: Connected
00:00:04 HTP: Web server active on sonoff-2372 with IP address 192.168.12.134
00:00:04 UPP: Multicast (re)joined
15:27:41 MQT: Attempting connection...
15:27:41 MQT: Connected
15:27:41 MQT: tele/sonoff/LWT = Online (retained)
15:27:41 MQT: cmnd/sonoff/POWER = 
15:27:41 MQT: tele/sonoff/INFO1 = {"Module":"Sonoff Basic","Version":"6.4.1.21(8a43cfb-sonoff)","FallbackTopic":"cmnd/DVES_438944_fb/","GroupTopic":"sonoffs"}
15:27:41 MQT: tele/sonoff/INFO2 = {"WebServerMode":"Admin","Hostname":"sonoff-2372","IPAddress":"192.168.12.134"}
15:27:41 MQT: tele/sonoff/INFO3 = {"RestartReason":"Fatal exception:28 flag:2 (EXCEPTION) epc1:0x40239f8e epc2:0x00000000 epc3:0x00000000 excvaddr:0x00000000 depc:0x00000000"}
15:27:41 MQT: stat/sonoff/RESULT = {"POWER":"OFF"}
15:27:41 MQT: stat/sonoff/POWER = OFF
15:27:41 UPP: Multicast (re)joined
15:27:49 MQT: tele/sonoff/STATE = {"Time":"2019-03-21T15:27:49","Uptime":"0T00:00:14","Vcc":2.997,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":80,"LinkCount":1,"Downtime":"0T00:00:04"}}

Jason2866 · 2019-03-21T14:38:45Z

Do you have a working version with this device?

arendst · 2019-03-21T16:15:23Z

Been testing for #5506 too and noticed that with wemo emulation enabled on a ailight it indeed has a lot of MQTT retries and almost no web gui response. I haven't seen exceptions yet but I will investigate.

arendst · 2019-03-21T16:38:58Z

@wongnam do you have a domoticz idx configured or are they all set to 0?

Jason2866 · 2019-03-21T19:02:23Z

@arendst Do you have tried different cores? I have tried 2.4.2 and stage core / sdk 2.2.1 and no issues
when tried with a wemos mini

wongnam · 2019-03-22T02:06:12Z

@wongnam do you have a domoticz idx configured or are they all set to 0?

I just used your official release default setting, do not touch to Domoticz idx and i also do not use Domoticz. even it will happen if i tried self-compile without domoticz feature.
if you want to replicate the exception -> set the Telemetry period (10)

I update more info. : the issue will happen when both MQTT are enable and connected with Emulation is turned on.

arendst · 2019-03-23T13:18:16Z

Cannot reproduce today :-(

6.5.0.2 20190325 * Change UDP initial message handling from string to char using static memory and add debug info (#5505)

arendst · 2019-03-25T15:10:22Z

@wongnam I still cannot reproduce but your problem may be due to too much UDP traffic.

Before the change I made today, for every received UDP message it was copied to a dynamic string before checking if it was a valid M-SEARCH packet. This could lead to your exceptions as string management can not cope with releasing memory.

The latest change only uses a string once a valid M-SEARCH packet has been recognised. It also adds some more debugging info (level 4) so pls give it a try and report back if you see many of these:

16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:35 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)
16:07:36 UDP: Packet (199)

Jason2866 · 2019-03-25T15:38:53Z

Alexa is still working :-)

arendst · 2019-03-25T15:47:43Z

@Jason2866 could you try if the below changes in xplg_wemohue.ino lines 242-264 still work pls?

/*
        String request = packet_buffer;
        request.toLowerCase();
        request.replace(" ", "");
        if (EMUL_WEMO == Settings.flag2.emulation) {
          if (request.indexOf(F("urn:belkin:device:**")) > 0) {    // type1 echo dot 2g, echo 1g's
            udp_response_mutex = true;
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, WemoRespondToMSearch, 1);
          }
          else if ((request.indexOf(F("upnp:rootdevice")) > 0) ||  // type2 Echo 2g (echo & echo plus)
                   (request.indexOf(F("ssdpsearch:all")) > 0) ||
                   (request.indexOf(F("ssdp:all")) > 0)) {
            udp_response_mutex = true;
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, WemoRespondToMSearch, 2);
          }
        }
        else if ((EMUL_HUE == Settings.flag2.emulation) &&
                ((request.indexOf(F("urn:schemas-upnp-org:device:basic:1")) > 0) ||
                 (request.indexOf(F("upnp:rootdevice")) > 0) ||
                 (request.indexOf(F("ssdpsearch:all")) > 0) ||
                 (request.indexOf(F("ssdp:all")) > 0))) {
            udp_response_mutex = true;
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, HueRespondToMSearch);
        }
*/
        UpperCase(packet_buffer, packet_buffer);
        RemoveSpace(packet_buffer);
        if (EMUL_WEMO == Settings.flag2.emulation) {
          if (strstr_P(packet_buffer, PSTR("URN:BELKIN:DEVICE:**"))) {  // type1 echo dot 2g, echo 1g's
            udp_response_mutex = true;
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, WemoRespondToMSearch, 1);
          }
          else if (strstr_P(packet_buffer, PSTR("UPNP:ROOTDEVICE")) ||  // type2 Echo 2g (echo & echo plus)
                   strstr_P(packet_buffer, PSTR("SSDPSEARCH:ALL")) ||
                   strstr_P(packet_buffer, PSTR("SSDP:ALL"))) {
            udp_response_mutex = true;
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, WemoRespondToMSearch, 2);
          }
        }
        else if ((EMUL_HUE == Settings.flag2.emulation) &&
                 (strstr_P(packet_buffer, PSTR("URN:SCHEMAS-UPNP-ORG:DEVICE:BASIC:1")) ||
                  strstr_P(packet_buffer, PSTR("UPNP:ROOTDEVICE")) ||
                  strstr_P(packet_buffer, PSTR("SSDPSEARCH:ALL")) ||
                  strstr_P(packet_buffer, PSTR("SSDP:ALL")))) {
            udp_response_mutex = true;
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, HueRespondToMSearch);
        }
      }

Jason2866 · 2019-03-25T16:12:44Z

@arendst Yes, is working fine. Tested with echo dot 2g
208 bytes saved :-)

wongnam · 2019-03-25T16:37:59Z

@arendst I saw many of this. yet to try your code(above).

00:00:00 CFG: Loaded from flash at FA, Count 10
00:00:00 SRC: Restart
00:00:00 Project sonoff Mini Hi-Fi Switch Version 6.5.0.2(sonoff)-2_4_2
00:00:00 WIF: Checking connection...
00:00:00 WIF: Attempting connection...
00:00:00 WIF: Connecting to AP1 iot-2 in mode 11N as minihifi-sw-6529...
00:00:01 WIF: Checking connection...
00:00:01 WIF: Attempting connection...
00:00:02 WIF: Checking connection...
00:00:02 WIF: Attempting connection...
00:00:03 WIF: Checking connection...
00:00:03 WIF: Attempting connection...
00:00:04 WIF: Checking connection...
00:00:04 WIF: Attempting connection...
00:00:05 WIF: Checking connection...
00:00:05 WIF: Attempting connection...
00:00:06 WIF: Checking connection...
00:00:06 WIF: Attempting connection...
00:00:07 WIF: Checking connection...
00:00:07 WIF: Attempting connection...
00:00:08 WIF: Checking connection...
00:00:08 WIF: Connected
00:00:08 HTP: Web server active on minihifi-sw-6529 with IP address 192.168.12.106
00:00:08 UPP: Multicast (re)joined
00:00:08 UDP: Packet (199)
00:00:08 UDP: Packet (199)
00:00:08 UDP: Packet (199)
00:00:08 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:09 UDP: Packet (199)
00:00:10 UDP: Packet (199)
00:00:10 UPP: Multicast disabled
00:00:10 MQT: Attempting connection...
00:00:10 MQT: Connected
00:00:10 MQT: tele/minihifi-sw/LWT = Online (retained)
00:00:10 MQT: cmnd/minihifi-sw/POWER = 
00:00:10 MQT: Subscribe to cmnd/minihifi-sw/#
00:00:10 MQT: Subscribe to cmnd/my_smarthome/#
00:00:10 MQT: Subscribe to cmnd/DVES_7C7981_fb/#
00:00:10 MQT: tele/minihifi-sw/INFO1 = {"Module":"Sonoff Basic","Version":"6.5.0.2(sonoff)","FallbackTopic":"cmnd/DVES_7C7981_fb/","GroupTopic":"my_smarthome"}
00:00:10 MQT: tele/minihifi-sw/INFO2 = {"WebServerMode":"Admin","Hostname":"minihifi-sw-6529","IPAddress":"192.168.12.106"}
00:00:10 MQT: tele/minihifi-sw/INFO3 = {"RestartReason":"Fatal exception:28 flag:2 (EXCEPTION) epc1:0x40230b2a epc2:0x00000000 epc3:0x00000000 excvaddr:0x00000000 depc:0x00000000"}
00:00:10 MQT: stat/minihifi-sw/RESULT = {"POWER":"OFF"}
00:00:10 MQT: stat/minihifi-sw/POWER = OFF
00:00:10 APP: Boot Count 4
00:00:10 SRC: MQTT
00:00:10 RSL: Received Topic cmnd/minihifi-sw/POWER, Data Size 12, Data PowerOnState
00:00:10 RSL: Group 0, Index 1, Command POWER, Data PowerOnState
00:00:10 MQT: stat/minihifi-sw/RESULT = {"POWER":"OFF"}
00:00:10 MQT: stat/minihifi-sw/POWER = OFF
00:00:10 CFG: Saved to flash at F9, Count 11, Bytes 3584
00:00:10 UPP: Multicast (re)joined
00:00:14 APP: (UTC) Mon Mar 25 16:35:37 2019, (DST) Sun Mar 31 02:00:00 2019, (STD) Sun Oct 27 03:00:00 2019
23:38:05 UDP: Packet (199)
23:38:05 UDP: Packet (199)
23:38:05 UDP: Packet (173)
23:38:05 UDP: M-SEARCH Packet from 192.168.12.137:65078
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 1
ST: urn:dial-multiscreen-org:service:dial:1
USER-AGENT: Google Chrome/73.0.3683.86 Windows


23:38:05 UDP: Packet (173)
23:38:05 UDP: M-SEARCH Packet from 192.168.12.137:65078
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 1
ST: urn:dial-multiscreen-org:service:dial:1
USER-AGENT: Google Chrome/73.0.3683.86 Windows


23:38:05 UDP: Packet (173)
23:38:05 UDP: M-SEARCH Packet from 192.168.12.137:65078
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 1
ST: urn:dial-multiscreen-org:service:dial:1
USER-AGENT: Google Chrome/73.0.3683.86 Windows


23:38:09 UDP: Packet (199)
23:38:09 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:10 UDP: Packet (199)
23:38:11 UDP: Packet (199)
23:38:11 UDP: Packet (199)
23:38:11 UDP: Packet (199)
23:38:11 UDP: Packet (199)
23:38:11 UDP: Packet (199)
23:38:11 UDP: Packet (199)
23:38:11 UDP: Packet (199)

Jason2866 · 2019-03-25T17:30:37Z

I have not that many...

00:00:00 Project sonoff 169 Version 6.5.0.2(sonoff)-STAGE
00:00:00 WIF: Connecting to AP1 Jason_Home_WLAN in mode 11N as sonoff-53CF5F-3935...
00:00:05 WIF: Connected
00:00:05 HTP: Web server active on sonoff-53CF5F-3935 with IP address 192.168.2.169
00:00:05 UPP: Multicast (re)joined
17:49:57 MQT: Attempting connection...
17:49:57 MQT: Connected
17:49:57 MQT: tele/sonoff-53CF5F/LWT = Online (retained)
17:49:57 MQT: cmnd/sonoff-53CF5F/POWER = 
17:49:57 MQT: tele/sonoff-53CF5F/INFO1 = {"Module":"Sonoff Basic","Version":"6.5.0.2(sonoff)","FallbackTopic":"cmnd/sonoff-53CF5F_fb/","GroupTopic":"sonoffs"}
17:49:57 MQT: tele/sonoff-53CF5F/INFO2 = {"WebServerMode":"Admin","Hostname":"sonoff-53CF5F-3935","IPAddress":"192.168.2.169"}
17:49:57 MQT: tele/sonoff-53CF5F/INFO3 = {"RestartReason":"Software/System restart"}
17:49:57 MQT: stat/sonoff-53CF5F/RESULT = {"POWER":"OFF"}
17:49:57 MQT: stat/sonoff-53CF5F/POWER = OFF
17:49:57 UPP: Multicast (re)joined
17:50:05 MQT: tele/sonoff-53CF5F/STATE = {"Time":"2019-03-25T17:50:05","Uptime":"0T00:00:15","Vcc":2.945,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"Jason_Home_WLAN","BSSId":"00:A0:57:2A:BD:19","Channel":13,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:05"}}
17:50:13 MQT: stat/sonoff-53CF5F/RESULT = {"POWER":"ON"}
17:50:13 MQT: stat/sonoff-53CF5F/POWER = ON
17:55:05 MQT: tele/sonoff-53CF5F/STATE = {"Time":"2019-03-25T17:55:05","Uptime":"0T00:05:15","Vcc":2.965,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":21,"POWER":"ON","Wifi":{"AP":1,"SSId":"Jason_Home_WLAN","BSSId":"00:A0:57:2A:BD:19","Channel":13,"RSSI":68,"LinkCount":1,"Downtime":"0T00:00:05"}}
18:00:05 MQT: tele/sonoff-53CF5F/STATE = {"Time":"2019-03-25T18:00:05","Uptime":"0T00:10:15","Vcc":2.946,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":23,"POWER":"ON","Wifi":{"AP":1,"SSId":"Jason_Home_WLAN","BSSId":"00:A0:57:2A:BD:19","Channel":13,"RSSI":68,"LinkCount":1,"Downtime":"0T00:00:05"}}
18:02:00 MQT: tele/sonoff-53CF5F/UPTIME = {"Time":"2019-03-25T18:02:00","Uptime":"0T00:12:10"}
18:05:05 MQT: tele/sonoff-53CF5F/STATE = {"Time":"2019-03-25T18:05:05","Uptime":"0T00:15:15","Vcc":2.947,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":22,"POWER":"ON","Wifi":{"AP":1,"SSId":"Jason_Home_WLAN","BSSId":"00:A0:57:2A:BD:19","Channel":13,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:05"}}
18:10:05 MQT: tele/sonoff-53CF5F/STATE = {"Time":"2019-03-25T18:10:05","Uptime":"0T00:20:15","Vcc":2.949,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":23,"POWER":"ON","Wifi":{"AP":1,"SSId":"Jason_Home_WLAN","BSSId":"00:A0:57:2A:BD:19","Channel":13,"RSSI":70,"LinkCount":1,"Downtime":"0T00:00:05"}}
18:15:05 MQT: tele/sonoff-53CF5F/STATE = {"Time":"2019-03-25T18:15:05","Uptime":"0T00:25:15","Vcc":2.965,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":23,"POWER":"ON","Wifi":{"AP":1,"SSId":"Jason_Home_WLAN","BSSId":"00:A0:57:2A:BD:19","Channel":13,"RSSI":66,"LinkCount":1,"Downtime":"0T00:00:05"}}
18:20:05 MQT: tele/sonoff-53CF5F/STATE = {"Time":"2019-03-25T18:20:05","Uptime":"0T00:30:15","Vcc":2.952,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":24,"POWER":"ON","Wifi":{"AP":1,"SSId":"Jason_Home_WLAN","BSSId":"00:A0:57:2A:BD:19","Channel":13,"RSSI":78,"LinkCount":1,"Downtime":"0T00:00:05"}}
18:25:05 MQT: tele/sonoff-53CF5F/STATE = {"Time":"2019-03-25T18:25:05","Uptime":"0T00:35:15","Vcc":2.948,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":23,"POWER":"ON","Wifi":{"AP":1,"SSId":"Jason_Home_WLAN","BSSId":"00:A0:57:2A:BD:19","Channel":13,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:05"}}
18:27:30 LOG: SerialLog 0, WebLog 4, SysLog 0, LogHost , LogPort 514, TelePeriod 300
18:27:30 HTP: Configuration
18:27:31 CFG: Saved to flash at F8, Count 69, Bytes 3584
18:27:33 HTP: Main Menu
18:27:34 HTP: Console
18:27:35 WIF: Checking connection...
18:27:35 WIF: Connected
18:27:45 UDP: Packet (199)
18:27:45 UDP: Packet (199)
18:27:45 UDP: Packet (199)
18:27:45 UDP: Packet (199)
18:27:45 UDP: Packet (199)
18:27:45 UDP: Packet (199)
18:27:46 UDP: Packet (199)
18:27:46 UDP: Packet (199)
18:27:46 UDP: Packet (199)
18:27:46 UDP: Packet (199)
18:27:46 UDP: Packet (199)
18:27:46 UDP: Packet (199)
18:27:47 UDP: Packet (199)
18:27:47 UDP: Packet (199)
18:27:47 UDP: Packet (199)
18:27:47 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:48 UDP: Packet (199)
18:27:49 UDP: Packet (199)
18:27:55 WIF: Checking connection...
18:27:55 WIF: Connected
18:28:15 WIF: Checking connection...
18:28:15 WIF: Connected
18:28:35 WIF: Checking connection...
18:28:35 WIF: Connected

narfel · 2019-03-26T08:06:45Z

I have the exact same problem as OT. In fact, before disabling Wemo Emulation i thought i have multiple broken boards (i'm using dev-boards). Does wemo emulation put substantial stress on the chip? Tested with a self compiled sonoff basic 6.5.0 on 2.3.

arendst · 2019-03-26T08:30:08Z

It's not so much that wemo emulation puts substantial stress on the chip as it is your UPnP environment. Both wemo and hue emulation use UDP for initial action and UDP traffic can be huge. Remember the Google Chromecast bug where it swamped your intranet with UDP messages bringing havoc to your UPnP devices.

Possible UDP message sources are Sonos, TP-Link routers and Chromecast.

Just enable emulation and log level 4 to see how much UDP packets come along. All packets need to be checked for a M-SEARCH type which might contain the wemo/hue request needed to control your emulation enabled device.

narfel · 2019-03-26T08:51:32Z

Here's the log lvl4 for a basic with the changes to xplg_wemohue.ino above if that's any help. My router is configured to not use UPnP and the only devices i can think of that might pollute are a firetv stick and a hue bridge. I can replicate this on actual sonoffs and dev-boards.

09:40:21 MQT: Attempting connection...
09:40:21 MQT: Connected
09:40:21 MQT: tele/sonoff/LWT = Online (retained)
09:40:21 MQT: cmnd/sonoff/POWER =
09:40:22 UPP: Multicast (re)joined
09:41:03 MQT: Attempting connection...
09:41:03 MQT: Connected
09:41:03 MQT: tele/sonoff/LWT = Online (retained)
09:41:03 MQT: cmnd/sonoff/POWER =
09:41:04 UPP: Multicast (re)joined
09:41:31 MQT: Attempting connection...
09:41:31 MQT: Connected
09:41:31 MQT: tele/sonoff/LWT = Online (retained)
09:41:31 MQT: cmnd/sonoff/POWER =
09:41:32 UPP: Multicast (re)joined
09:41:50 LOG: SerialLog 4, WebLog 4, SysLog 0, LogHost , LogPort 514, TelePeriod 300
09:41:50 HTP: Configuration
09:42:21 CFG: Saved to flash at F4, Count 24, Bytes 3584
09:42:22 UPP: Multicast disabled
09:42:22 MQT: Attempting connection...
09:42:22 MQT: Connected
09:42:22 MQT: tele/sonoff/LWT = Online (retained)
09:42:22 MQT: cmnd/sonoff/POWER =
09:42:22 MQT: Subscribe to cmnd/sonoff/#
09:42:22 MQT: Subscribe to cmnd/sonoffs/#
09:42:22 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
09:42:22 UPP: Multicast (re)joined
09:42:25 WIF: Checking connection...
09:42:25 WIF: Connected
09:42:27 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:42:45 WIF: Checking connection...
09:42:45 WIF: Connected
09:42:50 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:42:53 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:42:57 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:43:01 HTP: Configure Logging
09:43:04 HTP: Configuration
09:43:06 WIF: Checking connection...
09:43:06 WIF: Connected
09:43:07 HTP: Main Menu
09:43:08 HTP: Console
09:43:20 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:43:24 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:43:26 WIF: Checking connection...
09:43:26 WIF: Connected
09:43:27 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:43:46 WIF: Checking connection...
09:43:46 WIF: Connected
09:43:58 UPP: Multicast disabled
09:43:58 MQT: Attempting connection...
09:43:58 MQT: Connected
09:43:58 MQT: tele/sonoff/LWT = Online (retained)
09:43:58 MQT: cmnd/sonoff/POWER =
09:43:58 MQT: Subscribe to cmnd/sonoff/#
09:43:58 MQT: Subscribe to cmnd/sonoffs/#
09:43:58 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
09:43:58 UPP: Multicast (re)joined
09:44:16 WIF: Checking connection...
09:44:16 WIF: Connected
09:44:21 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:44:24 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:44:27 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:44:36 WIF: Checking connection...
09:44:36 WIF: Connected
09:44:51 UPP: WeMo Type 2, Response sent to 0.0.0.0:0
09:45:06 WIF: Checking connection...
09:45:06 WIF: Connected

arendst · 2019-03-26T09:02:35Z

Try replacing the complete function PollUdp with this:

void PollUdp(void)
{
  if (udp_connected && !udp_response_mutex && devices_present) {
    if (PortUdp.parsePacket()) {
      int len = PortUdp.read(packet_buffer, UDP_BUFFER_SIZE -1);
      if (len > 0) {
        packet_buffer[len] = 0;
      }

      AddLog_P2(LOG_LEVEL_DEBUG_MORE, PSTR("UDP: Packet (%d)"), len);
//      AddLog_P2(LOG_LEVEL_DEBUG_MORE, PSTR("\n%s"), packet_buffer);

      if (strstr_P(packet_buffer, PSTR("M-SEARCH"))) {
        udp_response_mutex = true;

        udp_remote_ip = PortUdp.remoteIP();
        udp_remote_port = PortUdp.remotePort();

        AddLog_P2(LOG_LEVEL_DEBUG_MORE, PSTR("UDP: M-SEARCH Packet from %s:%d\n%s"),
          udp_remote_ip.toString().c_str(), udp_remote_port, packet_buffer);

        UpperCase(packet_buffer, packet_buffer);
        RemoveSpace(packet_buffer);
        if (EMUL_WEMO == Settings.flag2.emulation) {
          if (strstr_P(packet_buffer, PSTR("URN:BELKIN:DEVICE:**"))) {  // type1 echo dot 2g, echo 1g's
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, WemoRespondToMSearch, 1);
            return;
          }
          else if (strstr_P(packet_buffer, PSTR("UPNP:ROOTDEVICE")) ||  // type2 Echo 2g (echo & echo plus)
                   strstr_P(packet_buffer, PSTR("SSDPSEARCH:ALL")) ||
                   strstr_P(packet_buffer, PSTR("SSDP:ALL"))) {
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, WemoRespondToMSearch, 2);
            return;
          }
        } else {
          if (strstr_P(packet_buffer, PSTR("URN:SCHEMAS-UPNP-ORG:DEVICE:BASIC:1")) ||
              strstr_P(packet_buffer, PSTR("UPNP:ROOTDEVICE")) ||
              strstr_P(packet_buffer, PSTR("SSDPSEARCH:ALL")) ||
              strstr_P(packet_buffer, PSTR("SSDP:ALL"))) {
            TickerMSearch.attach_ms(UDP_MSEARCH_SEND_DELAY, HueRespondToMSearch);
            return;
          }
        }
        udp_response_mutex = false;
      }
    }
    delay(1);
  }
}

narfel · 2019-03-26T09:13:31Z

Looks like exactly the same to me :/

00:00:00 CFG: Loaded from flash at F4, Count 24
00:00:00 SRC: Restart
00:00:00 Project sonoff Monitore Version 6.5.0(basic)-2_3_0
00:00:00 WIF: Checking connection...
00:00:00 WIF: Attempting connection...
00:00:00 WIF: Patch issue 2186
00:00:00 WIF: Connecting to AP1 in mode 11N as sonoff-6089...
00:00:01 WIF: Checking connection...
00:00:01 WIF: Attempting connection...
00:00:02 WIF: Checking connection...
00:00:02 WIF: Attempting connection...
00:00:03 WIF: Checking connection...
00:00:03 WIF: Attempting connection...
00:00:04 WIF: Checking connection...
00:00:04 WIF: Connected
00:00:04 HTP: Web server active on sonoff-6089 with IP address 192.168.1.103
00:00:04 UPP: Multicast (re)joined
00:00:05 UPP: Multicast disabled
00:00:05 MQT: Attempting connection...
00:00:05 MQT: Connected
00:00:05 MQT: tele/sonoff/LWT = Online (retained)
00:00:05 MQT: cmnd/sonoff/POWER =
00:00:05 MQT: Subscribe to cmnd/sonoff/#
00:00:05 MQT: Subscribe to cmnd/sonoffs/#
00:00:05 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
00:00:05 MQT: tele/sonoff/INFO1 = {"Module":"Generic","Version":"6.5.0(basic)","FallbackTopic":"cmnd/DVES_1737C9_fb/","GroupTopic":"sonoffs"}
00:00:05 MQT: tele/sonoff/INFO2 = {"WebServerMode":"Admin","Hostname":"sonoff-6089","IPAddress":"192.168.1.103"}
00:00:05 MQT: tele/sonoff/INFO3 = {"RestartReason":"External System"}
00:00:06 UPP: Multicast (re)joined
00:00:06 APP: (UTC) Tue Mar 26 09:06:03 2019, (DST) Sun Mar 31 02:00:00 2019, (STD) Sun Oct 27 03:00:00 2019
10:06:07 APP: Boot Count 15
10:06:07 CFG: Saved to flash at FB, Count 25, Bytes 3584
10:06:16 RSL: tele/sonoff/STATE = {"Time":"2019-03-26T10:06:11","Uptime":"0T00:00:14","Vcc":2.777,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"Wifi":{"AP":1,"SSId":"","BSSId":"A8:D3:F7:6B:A7:F0","Channel":5,"RSSI":62,"LinkCount":1,"Downtime":"0T00:00:04"}}
10:06:26 UPP: Multicast disabled
10:06:26 MQT: Attempting connection...
10:06:26 MQT: Connected
10:06:26 MQT: tele/sonoff/LWT = Online (retained)
10:06:26 MQT: cmnd/sonoff/POWER =
10:06:26 MQT: Subscribe to cmnd/sonoff/#
10:06:26 MQT: Subscribe to cmnd/sonoffs/#
10:06:26 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
10:06:27 UPP: Multicast (re)joined
10:06:31 WIF: Checking connection...
10:06:31 WIF: Connected
10:06:47 UPP: Multicast disabled
10:06:47 MQT: Attempting connection...
10:06:47 MQT: Connected
10:06:47 MQT: tele/sonoff/LWT = Online (retained)
10:06:47 MQT: cmnd/sonoff/POWER =
10:06:47 MQT: Subscribe to cmnd/sonoff/#
10:06:47 MQT: Subscribe to cmnd/sonoffs/#
10:06:47 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
10:06:48 UPP: Multicast (re)joined
10:06:56 WIF: Checking connection...
10:06:56 WIF: Connected
10:07:08 UPP: Multicast disabled
10:07:08 MQT: Attempting connection...
10:07:08 MQT: Connected
10:07:08 MQT: tele/sonoff/LWT = Online (retained)
10:07:08 MQT: cmnd/sonoff/POWER =
10:07:08 MQT: Subscribe to cmnd/sonoff/#
10:07:08 MQT: Subscribe to cmnd/sonoffs/#
10:07:08 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
10:07:09 UPP: Multicast (re)joined
10:07:11 HTP: Main Menu
10:07:13 HTP: Console

For some reason github just won't accept anything i put into code

arendst · 2019-03-26T09:14:23Z

Did you use three backquotes like

this

wongnam · 2019-03-26T09:14:37Z

@arendst it seam better now . the Sonoff response very fast.

update: below result is after i replaced void PollUdp(void) and remove lines 242-264.
update 2: No more Multicast Re-connect issue, Ask Alexa to turn off and on smoothly. Thanks

16:11:32 MQT: tele/smartplug/SENSOR = {"Time":"2019-03-26T16:11:32","AM2301":{"Temperature":33.6,"Humidity":52.9},"TempUnit":"C"}
16:11:54 MQT: stat/smartplug/STATUS = {"Status":{"Module":0,"FriendlyName":["Smart Plug"],"Topic":"smartplug","ButtonTopic":"0","Power":0,"PowerOnState":3,"LedState":1,"SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0}}
16:11:54 MQT: stat/smartplug/STATUS1 = {"StatusPRM":{"Baudrate":115200,"GroupTopic":"my_smarthome","OtaUrl":"http://thehackbox.org/tasmota/release/sonoff.bin","RestartReason":"Software/System restart","Uptime":"0T00:00:36","StartupUTC":"2019-03-26T09:11:18","Sleep":50,"CfgHolder":4617,"BootCount":6,"SaveCount":16,"SaveAddress":"F4000"}}
16:11:54 MQT: stat/smartplug/STATUS2 = {"StatusFWR":{"Version":"6.5.0.2(sonoff)","BuildDateTime":"2019-03-26T16:05:19","Boot":31,"Core":"2_4_2","SDK":"2.2.1(cfd48f3)"}}
16:11:54 MQT: stat/smartplug/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"SysLog":0,"LogHost":"192.168.12.155","LogPort":514,"SSId":["iot-2","Wong"],"TelePeriod":60,"Resolution":"55A180C0","SetOption":["00008009","280500000100000000000000000000000000","00000000"]}}
16:11:54 MQT: stat/smartplug/STATUS4 = {"StatusMEM":{"ProgramSize":481,"Free":520,"Heap":23,"ProgramFlashSize":1024,"FlashSize":1024,"FlashChipId":"14405E","FlashMode":3,"Features":["00000809","0F8A2390","2402A000","00B400CE","000013C0"]}}
16:11:54 MQT: stat/smartplug/STATUS5 = {"StatusNET":{"Hostname":"smartplug-1737","IPAddress":"192.168.12.111","Gateway":"192.168.12.1","Subnetmask":"255.255.255.0","DNSServer":"210.245.31.220","Mac":"2C:3A:E8:0F:86:C9","Webserver":2,"WifiConfig":4}}
16:11:54 MQT: stat/smartplug/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.12.155","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_0F86C9","MqttUser":"admin","MqttCount":1,"MAX_PACKET_SIZE":1000,"KEEPALIVE":15}}
16:11:54 MQT: stat/smartplug/STATUS7 = {"StatusTIM":{"UTC":"Tue Mar 26 09:11:54 2019","Local":"Tue Mar 26 16:11:54 2019","StartDST":"Sun Mar 31 02:00:00 2019","EndDST":"Sun Oct 27 03:00:00 2019","Timezone":"+07:00","Sunrise":"05:53","Sunset":"18:03"}}
16:11:54 MQT: stat/smartplug/STATUS10 = {"StatusSNS":{"Time":"2019-03-26T16:11:54","AM2301":{"Temperature":33.6,"Humidity":53.0},"TempUnit":"C"}}
16:11:54 MQT: stat/smartplug/STATUS11 = {"StatusSTS":{"Time":"2019-03-26T16:11:54","Uptime":"0T00:00:36","Vcc":3.448,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":66,"LinkCount":1,"Downtime":"0T00:00:04"}}}
16:12:03 CMD: weblog 4
16:12:03 MQT: stat/smartplug/RESULT = {"WebLog":4}
16:12:03 CFG: Saved to flash at FB, Count 17, Bytes 3584
16:12:04 UDP: Packet (199)
16:12:04 UDP: Packet (199)
16:12:06 UDP: Packet (199)
16:12:06 UDP: Packet (199)
16:12:06 UDP: Packet (199)
16:12:06 UDP: Packet (199)
16:12:06 UDP: Packet (199)
16:12:14 UDP: Packet (199)
16:12:14 UDP: Packet (199)
16:12:17 HTP: Main Menu
16:12:19 HTP: Configuration
16:12:20 HTP: Configure Other
16:12:22 WIF: Checking connection...
16:12:22 WIF: Connected
16:12:22 HTP: Configuration
16:12:24 UDP: Packet (199)
16:12:24 UDP: Packet (199)
16:12:24 UDP: Packet (199)
16:12:24 HTP: Configure Logging
16:12:28 HTP: Configuration
16:12:30 HTP: Main Menu
16:12:32 MQT: tele/smartplug/STATE = {"Time":"2019-03-26T16:12:32","Uptime":"0T00:01:14","Vcc":3.463,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":64,"LinkCount":1,"Downtime":"0T00:00:04"}}
16:12:32 MQT: tele/smartplug/SENSOR = {"Time":"2019-03-26T16:12:32","AM2301":{"Temperature":33.6,"Humidity":52.9},"TempUnit":"C"}
16:12:33 HTP: Console
16:12:34 UDP: Packet (199)
16:12:34 UDP: Packet (199)
16:12:34 UDP: Packet (199)
16:12:42 WIF: Checking connection...
16:12:42 WIF: Connected
16:12:44 UDP: Packet (199)
16:12:44 UDP: Packet (199)
16:12:44 UDP: Packet (199)
16:12:46 UDP: Packet (199)
16:12:46 UDP: Packet (199)
16:12:54 UDP: Packet (199)
16:12:54 UDP: Packet (199)
16:12:54 UDP: Packet (199)
16:13:02 WIF: Checking connection...
16:13:02 WIF: Connected
16:13:04 UDP: Packet (199)
16:13:04 UDP: Packet (199)
16:13:04 UDP: Packet (199)
16:13:12 UDP: Packet (199)
16:13:12 UDP: Packet (199)
16:13:12 UDP: Packet (199)
16:13:12 UDP: Packet (199)
16:13:12 UDP: Packet (199)
16:13:12 UDP: Packet (199)
16:13:14 UDP: Packet (199)
16:13:14 UDP: Packet (199)
16:13:14 UDP: Packet (199)
16:13:14 SRC: MQTT
16:13:14 RSL: Received Topic cmnd/smartplug/POWER, Data Size 2, Data on
16:13:14 RSL: Group 0, Index 1, Command POWER, Data on
16:13:14 MQT: stat/smartplug/RESULT = {"POWER":"ON"}
16:13:14 MQT: stat/smartplug/POWER = ON
16:13:14 SRC: MQTT
16:13:14 RSL: Received Topic cmnd/smartplug/POWER, Data Size 12, Data PowerOnState
16:13:14 RSL: Group 0, Index 1, Command POWER, Data PowerOnState
16:13:14 MQT: stat/smartplug/RESULT = {"POWER":"ON"}
16:13:14 MQT: stat/smartplug/POWER = ON
16:13:15 CFG: Saved to flash at FA, Count 18, Bytes 3584
16:13:22 WIF: Checking connection...
16:13:22 WIF: Connected
16:13:24 UDP: Packet (199)
16:13:24 UDP: Packet (199)
16:13:24 UDP: Packet (199)
16:13:32 MQT: tele/smartplug/STATE = {"Time":"2019-03-26T16:13:32","Uptime":"0T00:02:14","Vcc":3.447,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"ON","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":68,"LinkCount":1,"Downtime":"0T00:00:04"}}
16:13:32 MQT: tele/smartplug/SENSOR = {"Time":"2019-03-26T16:13:32","AM2301":{"Temperature":33.5,"Humidity":53.0},"TempUnit":"C"}
16:13:34 UDP: Packet (199)
16:13:34 UDP: Packet (199)
16:13:34 UDP: Packet (199)
16:13:38 SRC: MQTT
16:13:38 RSL: Received Topic cmnd/smartplug/POWER, Data Size 3, Data off
16:13:38 RSL: Group 0, Index 1, Command POWER, Data off
16:13:38 MQT: stat/smartplug/RESULT = {"POWER":"OFF"}
16:13:38 MQT: stat/smartplug/POWER = OFF
16:13:38 SRC: MQTT
16:13:38 RSL: Received Topic cmnd/smartplug/POWER, Data Size 12, Data PowerOnState
16:13:38 RSL: Group 0, Index 1, Command POWER, Data PowerOnState
16:13:38 MQT: stat/smartplug/RESULT = {"POWER":"OFF"}
16:13:38 MQT: stat/smartplug/POWER = OFF
16:13:38 CFG: Saved to flash at F9, Count 19, Bytes 3584
16:13:42 WIF: Checking connection...
16:13:42 WIF: Connected
16:13:44 UDP: Packet (199)
16:13:44 UDP: Packet (199)

arendst · 2019-03-26T09:21:23Z

@wongnam from your log I see you do not have excessive UDP traffic; it looks almost like mine where most Packet (199) are coming from my routers.

@narfel I do not see those MQTT reconnects but I wonder what version you are using as the log states 6.5.0(basic) where the latest dev release is 6.5.0.2...

wongnam · 2019-03-26T09:24:33Z

@arendst Yes, i saw many of Packet (199) but I don't understand what this is. issue or normal?
BTW, My router is Draytek Vigor 2926 with IGMP Snooping enabled. My Wifi is an AP from Aruba IAP-315 (no route)

update my result, it's perfect @arendst . Thank you.

00:00:00 CFG: Loaded from flash at F7, Count 31
00:00:00 SRC: Restart
00:00:00 Project sonoff test plug Version 6.5.0.2(sonoff)-2_4_2
00:00:00 WIF: Checking connection...
00:00:00 WIF: Attempting connection...
00:00:00 WIF: Connecting to AP1 iot-2 in mode 11N as minihifi-sw-6529...
00:00:01 WIF: Checking connection...
00:00:01 WIF: Attempting connection...
00:00:02 WIF: Checking connection...
00:00:02 WIF: Attempting connection...
00:00:03 WIF: Checking connection...
00:00:03 WIF: Attempting connection...
00:00:04 WIF: Checking connection...
00:00:04 WIF: Connected
00:00:04 HTP: Web server active on minihifi-sw-6529 with IP address 192.168.12.106
00:00:04 UPP: Multicast (re)joined
00:00:04 APP: (UTC) Tue Mar 26 09:54:32 2019, (DST) Sun Mar 31 02:00:00 2019, (STD) Sun Oct 27 03:00:00 2019
16:54:34 UPP: Multicast disabled
16:54:34 MQT: Attempting connection...
16:54:34 MQT: Connected
16:54:34 MQT: tele/minihifi-sw/LWT = Online (retained)
16:54:34 MQT: cmnd/minihifi-sw/POWER = 
16:54:34 MQT: Subscribe to cmnd/minihifi-sw/#
16:54:34 MQT: Subscribe to cmnd/my_smarthome/#
16:54:34 MQT: Subscribe to cmnd/DVES_7C7981_fb/#
16:54:34 MQT: tele/minihifi-sw/INFO1 = {"Module":"Sonoff Basic","Version":"6.5.0.2(sonoff)","FallbackTopic":"cmnd/DVES_7C7981_fb/","GroupTopic":"my_smarthome"}
16:54:34 MQT: tele/minihifi-sw/INFO2 = {"WebServerMode":"Admin","Hostname":"minihifi-sw-6529","IPAddress":"192.168.12.106"}
16:54:34 MQT: tele/minihifi-sw/INFO3 = {"RestartReason":"Software/System restart"}
16:54:34 MQT: stat/minihifi-sw/RESULT = {"POWER":"OFF"}
16:54:34 MQT: stat/minihifi-sw/POWER = OFF
16:54:34 SRC: MQTT
16:54:34 RSL: Received Topic cmnd/minihifi-sw/POWER, Data Size 12, Data PowerOnState
16:54:34 RSL: Group 0, Index 1, Command POWER, Data PowerOnState
16:54:34 MQT: stat/minihifi-sw/RESULT = {"POWER":"OFF"}
16:54:34 MQT: stat/minihifi-sw/POWER = OFF
16:54:34 UPP: Multicast (re)joined
16:54:34 HTP: Main Menu
16:54:38 APP: Boot Count 8
16:54:38 HTP: Console
16:54:38 CFG: Saved to flash at F6, Count 32, Bytes 3584
16:54:42 MQT: tele/minihifi-sw/STATE = {"Time":"2019-03-26T16:54:42","Uptime":"0T00:00:14","Vcc":3.372,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":48,"LinkCount":1,"Downtime":"0T00:00:04"}}
16:54:44 HTP: WeMo basic event
16:54:47 HTP: WeMo basic event
16:54:48 HTP: WeMo basic event
16:54:48 SRC: Wemo
16:54:48 MQT: stat/minihifi-sw/RESULT = {"POWER":"ON"}
16:54:48 MQT: stat/minihifi-sw/POWER = ON
16:54:48 SRC: MQTT
16:54:48 RSL: Received Topic cmnd/minihifi-sw/POWER, Data Size 12, Data PowerOnState
16:54:48 RSL: Group 0, Index 1, Command POWER, Data PowerOnState
16:54:48 MQT: stat/minihifi-sw/RESULT = {"POWER":"ON"}
16:54:48 MQT: stat/minihifi-sw/POWER = ON
16:54:48 CFG: Saved to flash at F5, Count 33, Bytes 3584
16:54:50 UDP: Packet (199)
16:54:50 UDP: Packet (199)
16:54:50 UDP: Packet (199)
16:54:50 UDP: Packet (199)
16:54:51 UDP: Packet (199)
16:54:52 HTP: WeMo basic event
16:54:52 WIF: Checking connection...
16:54:52 WIF: Connected
16:54:55 HTP: WeMo basic event
16:54:55 HTP: WeMo basic event
16:54:55 SRC: Wemo
16:54:55 MQT: stat/minihifi-sw/RESULT = {"POWER":"OFF"}
16:54:55 MQT: stat/minihifi-sw/POWER = OFF
16:54:55 SRC: MQTT
16:54:55 RSL: Received Topic cmnd/minihifi-sw/POWER, Data Size 12, Data PowerOnState
16:54:55 RSL: Group 0, Index 1, Command POWER, Data PowerOnState
16:54:55 MQT: stat/minihifi-sw/RESULT = {"POWER":"OFF"}
16:54:55 MQT: stat/minihifi-sw/POWER = OFF
16:54:56 CFG: Saved to flash at F4, Count 34, Bytes 3584
16:55:04 SRC: MQTT
16:55:04 RSL: Received Topic cmnd/minihifi-sw/STATUS, Data Size 1, Data 0
16:55:04 RSL: Group 0, Index 1, Command STATUS, Data 0
16:55:04 MQT: stat/minihifi-sw/STATUS = {"Status":{"Module":1,"FriendlyName":["test plug"],"Topic":"minihifi-sw","ButtonTopic":"","Power":0,"PowerOnState":3,"LedState":1,"SaveData":1,"SaveState":1,"SwitchTopic":"","SwitchMode":[0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0}}
16:55:04 MQT: stat/minihifi-sw/STATUS1 = {"StatusPRM":{"Baudrate":115200,"GroupTopic":"my_smarthome","OtaUrl":"http://thehackbox.org/tasmota/release/sonoff.bin","RestartReason":"Software/System restart","Uptime":"0T00:00:36","StartupUTC":"2019-03-26T09:54:28","Sleep":50,"CfgHolder":4617,"BootCount":8,"SaveCount":34,"SaveAddress":"F4000"}}
16:55:04 MQT: stat/minihifi-sw/STATUS2 = {"StatusFWR":{"Version":"6.5.0.2(sonoff)","BuildDateTime":"2019-03-26T16:05:19","Boot":31,"Core":"2_4_2","SDK":"2.2.1(cfd48f3)"}}
16:55:04 MQT: stat/minihifi-sw/STATUS3 = {"StatusLOG":{"SerialLog":0,"WebLog":4,"SysLog":1,"LogHost":"192.168.12.155","LogPort":514,"SSId":["iot-2","Wong"],"TelePeriod":60,"Resolution":"55A180C0","SetOption":["00008009","280500000100000000000000000000000000","00000000"]}}
16:55:04 MQT: stat/minihifi-sw/STATUS4 = {"StatusMEM":{"ProgramSize":481,"Free":520,"Heap":22,"ProgramFlashSize":1024,"FlashSize":1024,"FlashChipId":"14405E","FlashMode":3,"Features":["00000809","0F8A2390","2402A000","00B400CE","000013C0"]}}
16:55:04 MQT: stat/minihifi-sw/STATUS5 = {"StatusNET":{"Hostname":"minihifi-sw-6529","IPAddress":"192.168.12.106","Gateway":"192.168.12.1","Subnetmask":"255.255.255.0","DNSServer":"210.245.31.220","Mac":"5C:CF:7F:7C:79:81","Webserver":2,"WifiConfig":4}}
16:55:04 MQT: stat/minihifi-sw/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.12.155","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_7C7981","MqttUser":"admin","MqttCount":1,"MAX_PACKET_SIZE":1000,"KEEPALIVE":15}}
16:55:04 MQT: stat/minihifi-sw/STATUS7 = {"StatusTIM":{"UTC":"Tue Mar 26 09:55:04 2019","Local":"Tue Mar 26 16:55:04 2019","StartDST":"Sun Mar 31 02:00:00 2019","EndDST":"Sun Oct 27 03:00:00 2019","Timezone":"+07:00","Sunrise":"05:53","Sunset":"18:03"}}
16:55:04 MQT: stat/minihifi-sw/STATUS10 = {"StatusSNS":{"Time":"2019-03-26T16:55:04"}}
16:55:04 MQT: stat/minihifi-sw/STATUS11 = {"StatusSTS":{"Time":"2019-03-26T16:55:04","Uptime":"0T00:00:36","Vcc":3.369,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"iot-2","BSSId":"38:17:C3:F1:90:01","Channel":1,"RSSI":52,"LinkCount":1,"Downtime":"0T00:00:04"}}}
16:55:04 UDP: Packet (199)
16:55:04 UDP: Packet (199)
16:55:12 WIF: Checking connection...
16:55:12 WIF: Connected
16:55:14 UDP: Packet (199)
16:55:18 UDP: Packet (199)
16:55:18 UDP: Packet (199)
16:55:18 UDP: Packet (199)
16:55:18 UDP: Packet (199)
16:55:19 UDP: Packet (199)
16:55:24 UDP: Packet (199)
16:55:24 UDP: Packet (199)
16:55:24 UDP: Packet (199)

Increase emulation stability (#5505)

narfel · 2019-03-26T09:53:35Z

@arendst Yes, my initial idea was to just upload via vscode to intialize the board and then use a hackbox binary. However when the wemo troubles began i didn't switch to dev. Here is a log of 6.5.0.2/2.4.2 with above replaced PollUdp function. I can't really see anything different in behaviour or even something that would raise concerns in the log. Any further idea how to troubleshoot? Comparing my log against @wongnams there seems to be no UDP messages for me but a lot of MQT reconnects. Is this even the same issue? I don't want to pollute the thread, yet the erroneous behavior is exactly like in the original post.

00:00:00 Project sonoff NodeMCU Version 6.5.0.2(basic)-2_4_2
00:00:00 WIF: Checking connection...
00:00:00 WIF: Attempting connection...
00:00:00 WIF: Connecting to AP1 <mySSID> in mode 11N as sonoff-6089...
00:00:01 WIF: Checking connection...
00:00:01 WIF: Attempting connection...
00:00:02 WIF: Checking connection...
00:00:02 WIF: Attempting connection...
00:00:03 WIF: Checking connection...
00:00:03 WIF: Attempting connection...
00:00:04 WIF: Checking connection...
00:00:04 WIF: Connected
00:00:04 HTP: Web server active on sonoff-6089 with IP address 192.168.1.103
00:00:04 UPP: Multicast (re)joined
00:00:04 APP: (UTC) Tue Mar 26 09:39:07 2019, (DST) Sun Mar 31 02:00:00 2019, (STD) Sun Oct 27 03:00:00 2019
10:39:09 UPP: Multicast disabled
10:39:09 MQT: Attempting connection...
10:39:09 MQT: Connected
10:39:09 MQT: tele/sonoff/LWT = Online (retained)
10:39:09 MQT: cmnd/sonoff/POWER = 
10:39:09 MQT: Subscribe to cmnd/sonoff/#
10:39:09 MQT: Subscribe to cmnd/sonoffs/#
10:39:09 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
10:39:09 MQT: tele/sonoff/INFO1 = {"Module":"Generic","Version":"6.5.0.2(basic)","FallbackTopic":"cmnd/DVES_1737C9_fb/","GroupTopic":"sonoffs"}
10:39:09 MQT: tele/sonoff/INFO2 = {"WebServerMode":"Admin","Hostname":"sonoff-6089","IPAddress":"192.168.1.103"}
10:39:09 MQT: tele/sonoff/INFO3 = {"RestartReason":"External System"}
10:39:09 UPP: Multicast (re)joined
10:39:13 APP: Boot Count 16
10:39:13 CFG: Saved to flash at FA, Count 28, Bytes 3584
10:39:14 HTP: Main Menu
10:39:14 HTP: Main Menu
10:39:22 RSL: tele/sonoff/STATE = {"Time":"2019-03-26T10:39:17","Uptime":"0T00:00:14","Vcc":3.024,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"Wifi":{"AP":1,"SSId":"<mySSID>","BSSId":"A8:D3:F7:6B:A7:F0","Channel":5,"RSSI":66,"LinkCount":1,"Downtime":"0T00:00:04"}}
10:39:23 UPP: Multicast disabled
10:39:23 MQT: Attempting connection...
10:39:23 MQT: Connected
10:39:23 MQT: tele/sonoff/LWT = Online (retained)
10:39:23 MQT: cmnd/sonoff/POWER = 
10:39:23 MQT: Subscribe to cmnd/sonoff/#
10:39:23 MQT: Subscribe to cmnd/sonoffs/#
10:39:23 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
10:39:24 UPP: Multicast (re)joined
10:39:28 HTP: Console
10:39:33 WIF: Checking connection...
10:39:33 WIF: Connected
10:39:53 WIF: Checking connection...
10:39:53 WIF: Connected
10:39:59 UPP: Multicast disabled
10:39:59 MQT: Attempting connection...
10:39:59 MQT: Connected
10:39:59 MQT: tele/sonoff/LWT = Online (retained)
10:39:59 MQT: cmnd/sonoff/POWER = 
10:39:59 MQT: Subscribe to cmnd/sonoff/#
10:39:59 MQT: Subscribe to cmnd/sonoffs/#
10:39:59 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
10:39:59 UPP: Multicast (re)joined
10:40:11 HTP: Main Menu
10:40:13 HTP: Information
10:40:17 WIF: Checking connection...
10:40:17 WIF: Connected
10:40:24 UPP: Multicast disabled
10:40:24 MQT: Attempting connection...
10:40:24 MQT: Connected
10:40:24 MQT: tele/sonoff/LWT = Online (retained)
10:40:24 MQT: cmnd/sonoff/POWER = 
10:40:24 MQT: Subscribe to cmnd/sonoff/#
10:40:24 MQT: Subscribe to cmnd/sonoffs/#
10:40:24 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
10:40:24 HTP: Main Menu
10:40:24 UPP: Multicast (re)joined
10:40:30 HTP: Information
10:40:34 HTP: Main Menu
10:40:38 HTP: Configuration
10:40:40 HTP: Configure Logging
10:40:42 HTP: Configuration
10:40:44 WIF: Checking connection...
10:40:44 WIF: Connected
10:40:58 UPP: Multicast disabled
10:40:58 MQT: Attempting connection...
10:40:58 MQT: Connected
10:40:58 MQT: tele/sonoff/LWT = Online (retained)
10:40:58 MQT: cmnd/sonoff/POWER = 
10:40:58 MQT: Subscribe to cmnd/sonoff/#
10:40:58 MQT: Subscribe to cmnd/sonoffs/#
10:40:58 MQT: Subscribe to cmnd/DVES_1737C9_fb/#
10:40:59 UPP: Multicast (re)joined
10:40:59 HTP: Configure Other
10:41:03 HTP: Configuration
10:41:05 HTP: Configure Logging
10:41:06 HTP: Configuration
10:41:08 WIF: Checking connection...
10:41:08 WIF: Connected

wongnam · 2019-03-26T10:03:55Z

@narfel My log is no MQT re-connection. the MQTT command is sending from my SmartHome system to check the PowerOnState of the Relay only, please ignore it.

i have just updated the 2nd log above that it shown wemo in action very well.

arendst · 2019-03-26T10:16:03Z

OK. I think @narfel you have another problem with mqtt comms. See wiki for troubleshooting wifi problems.

@wongnam I think the issue here is solved. pls close this one.

wongnam · 2019-03-26T10:20:02Z

I confirm the issue is fixed. Thank you very much.

Jason2866 mentioned this issue Mar 21, 2019

Alexa an Belkin Emulation for Sonoff dual R2 #3327

Closed

1 task

arendst added troubleshooting Type - Troubleshooting Requires more research (devs) Action - Issue requires more research labels Mar 21, 2019

arendst mentioned this issue Mar 21, 2019

AiLight / EleLight doesn't work properly and crashes #5506

Closed

10 tasks

ascillato2 added the awaiting feedback Action - Waiting for response or more information label Mar 21, 2019

Jason2866 mentioned this issue Mar 22, 2019

change power will reboot device when MQTT enabled #5511

Closed

10 tasks

arendst self-assigned this Mar 23, 2019

arendst removed their assignment Mar 25, 2019

arendst added a commit that referenced this issue Mar 25, 2019

6.5.0.2 Change UDP initial message handling

1c7fb82

6.5.0.2 20190325 * Change UDP initial message handling from string to char using static memory and add debug info (#5505)

arendst added a commit that referenced this issue Mar 26, 2019

Increase emulation stability (#5505)

bf8845c

Increase emulation stability (#5505)

arendst added fixed Result - The work on the issue has ended and removed Requires more research (devs) Action - Issue requires more research awaiting feedback Action - Waiting for response or more information labels Mar 26, 2019

wongnam closed this as completed Mar 26, 2019

When the WeMo emulation feature is enabled, the web ui is almost frozen. #5505

When the WeMo emulation feature is enabled, the web ui is almost frozen. #5505

Comments

wongnam commented Mar 21, 2019 • edited Loading

BUG DESCRIPTION

TO REPRODUCE

wongnam commented Mar 21, 2019 • edited Loading

Jason2866 commented Mar 21, 2019

wongnam commented Mar 21, 2019

Jason2866 commented Mar 21, 2019 • edited Loading

Jason2866 commented Mar 21, 2019

wongnam commented Mar 21, 2019

Jason2866 commented Mar 21, 2019

wongnam commented Mar 21, 2019

Jason2866 commented Mar 21, 2019

Jason2866 commented Mar 21, 2019

Jason2866 commented Mar 21, 2019 • edited Loading

wongnam commented Mar 21, 2019

Jason2866 commented Mar 21, 2019

arendst commented Mar 21, 2019

arendst commented Mar 21, 2019

Jason2866 commented Mar 21, 2019

wongnam commented Mar 22, 2019 • edited Loading

arendst commented Mar 23, 2019 • edited Loading

arendst commented Mar 25, 2019

Jason2866 commented Mar 25, 2019

arendst commented Mar 25, 2019

Jason2866 commented Mar 25, 2019 • edited Loading

wongnam commented Mar 25, 2019 • edited Loading

Jason2866 commented Mar 25, 2019

narfel commented Mar 26, 2019

arendst commented Mar 26, 2019 • edited Loading

narfel commented Mar 26, 2019 • edited Loading

arendst commented Mar 26, 2019

narfel commented Mar 26, 2019

arendst commented Mar 26, 2019

wongnam commented Mar 26, 2019 • edited Loading

arendst commented Mar 26, 2019

wongnam commented Mar 26, 2019 • edited Loading

narfel commented Mar 26, 2019

wongnam commented Mar 26, 2019

arendst commented Mar 26, 2019

wongnam commented Mar 26, 2019

wongnam commented Mar 21, 2019 •

edited

Loading

wongnam commented Mar 21, 2019 •

edited

Loading

Jason2866 commented Mar 21, 2019 •

edited

Loading

Jason2866 commented Mar 21, 2019 •

edited

Loading

wongnam commented Mar 22, 2019 •

edited

Loading

arendst commented Mar 23, 2019 •

edited

Loading

Jason2866 commented Mar 25, 2019 •

edited

Loading

wongnam commented Mar 25, 2019 •

edited

Loading

arendst commented Mar 26, 2019 •

edited

Loading

narfel commented Mar 26, 2019 •

edited

Loading

wongnam commented Mar 26, 2019 •

edited

Loading

wongnam commented Mar 26, 2019 •

edited

Loading