[Shelly Plus 1PM] console is flooded with messages about garbage coming from the serial port

[tm-107]

PROBLEM DESCRIPTION

On my Shelly Plus 1PM, the console is flooded with messages about garbage coming from the serial port.
Nothing is connected to the device except the power lines (L+N).
I have now taken the device to work to rule out interference from my WiFi or other radio transmitters. To no avail.

REQUESTED INFORMATION

Make sure your have performed every step and checked the applicable boxes before submitting your issue. Thank you!

• Read the Contributing Guide and Policy and the Code of Conduct
• Searched the problem in issues
• Searched the problem in discussions
• Searched the problem in the docs
• Searched the problem in the chat
• Device used (e.g., Sonoff Basic): Shelly Plus 1PM
• Tasmota binary firmware version number used: 14.3.0 (release-solo1)
  • Pre-compiled
  • Self-compiled
• Flashing tools used: mgos32-to-tasmota32
• Provide the output of command: Backlog Template; Module; GPIO 255:

  Configuration output here:
19:31:53.213 RSL: RESULT = {"NAME":"Shelly Plus 1PM","GPIO":[0,0,0,0,192,2720,0,0,0,0,0,0,0,0,2656,0,0,0,0,2624,0,160,224,0,0,0,0,0,0,0,0,0,0,0,0,0],"FLAG":0,"BASE":1}
[...]
19:31:53.432 RSL: RESULT = {"Module":{"0":"Shelly Plus 1PM"}}
[...]
19:31:53.651 RSL: RESULT = {"GPIO0":{"0":"None"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"192":"Switch_n1"},"GPIO5":{"2720":"BL0937 CF"},"GPIO6":{"0":"None"},"GPIO7":{"0":"None"},"GPIO8":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO11":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"0":"None"},"GPIO14":{"0":"None"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"},"GPIO17":{"0":"None"},"GPIO18":{"2656":"HLWBL CF1"},"GPIO19":{"0":"None"},"GPIO20":{"0":"None"},"GPIO21":{"0":"None"},"GPIO22":{"0":"None"},"GPIO23":{"2624":"HLWBL SEL_i"},"GPIO24":{"0":"None"},"GPIO25":{"160":"Switch1"},"GPIO26":{"224":"Relay1"},"GPIO27":{"0":"None"},"GPIO32":{"0":"None"},"GPIO33":{"0":"None"},"GPIO34":{"0":"None"},"GPIO35":{"0":"None"},"GPIO36":{"0":"None"},"GPIO37":{"0":"None"},"GPIO38":{"0":"None"},"GPIO39":{"0":"None"}}

• If using rules, provide the output of this command: Backlog Rule1; Rule2; Rule3:

  Rules output here:

• Provide the output of this command: Status 0:

  STATUS 0 output here:
19:19:04.199 CMD: Status 0
19:19:04.201 SRC: WebConsole from 192.168.xxx.xxx
19:19:04.203 CMD: Grp 0, Cmd 'STATUS', Idx 1, Len 1, Pld 0, Data '0'
19:19:04.206 RSL: STATUS = {"Status":{"Module":0,"DeviceName":"WWWP","FriendlyName":["WWWP"],"Topic":"tasmota_219170","ButtonTopic":"0","Power":"1","PowerLock":"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}}
19:19:04.247 RSL: STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota32/release/tasmota32solo1.bin","RestartReason":"Software reset CPU","Uptime":"0T00:01:20","StartupUTC":"2024-11-20T18:17:44","Sleep":50,"CfgHolder":4617,"BootCount":11,"BCResetTime":"2024-11-19T23:50:47","SaveCount":28}}
19:19:04.287 RSL: STATUS2 = {"StatusFWR":{"Version":"14.3.0(release-solo1)single-core","BuildDateTime":"2024-10-15T08:21:26","Core":"3_1_0","SDK":"5.3.1.240924","CpuFrequency":240,"Hardware":"ESP32-U4WDH-D v3.0","CR":"452/699"}}
19:19:04.303 RSL: STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":4,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["xxx","xxx"],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008001","2805C80001000600003C5A0A192800000000","00000080","00006000","00004000","00000000"]}}
19:19:04.336 RSL: STATUS4 = {"StatusMEM":{"ProgramSize":1960,"Free":727,"Heap":150,"StackLowMark":3,"PsrMax":0,"PsrFree":0,"ProgramFlashSize":4096,"FlashSize":4096,"FlashChipId":"164020","FlashFrequency":80,"FlashMode":"DIO","Features":["0809","9F9AD7DF","0015A001","B7F7BFCF","05DA9BC4","E0360DC7","480840D2","20200000","D4BC482D","810A80B1","00000014"],"Drivers":"1,!2,3,!4,!5,!7,!8,9,10,11,!12,!14,!16,!17,!20,!21,!24,26,!27,29,!34,!35,38,50,52,!59,!60,62,!63,!66,!67,!68,!73,82,!86,!87,!88,!121","Sensors":"1,2,3,5,6,7,8,9,10,11,12,13,14,15,17,18,19,20,21,22,26,31,34,37,39,40,42,43,45,51,52,55,56,58,59,64,66,67,74,85,92,95,98,103,105,109,127","I2CDriver":"7,8,9,10,11,12,13,14,15,17,18,20,24,29,31,36,41,42,44,46,48,58,62,65,69,76,77,82,89"}}
19:19:04.409 RSL: STATUS5 = {"StatusNET":{"Hostname":"tasmota-219170-4464","IPAddress":"192.168.xxx.xxx","Gateway":"192.168.xxx.xxx","Subnetmask":"255.255.255.0","DNSServer1":"192.168.xxx.xxx","DNSServer2":"0.0.0.0","Mac":"B4:8A:0A:xx:xx:xx","IP6Global":"2001:9e8:1025:7400:xxxx:xxxx:xxxx:xxxx","IP6Local":"fe80::xxxx:xxxx:xxxx:xxxx%st1","Ethernet":{"Hostname":"","IPAddress":"0.0.0.0","Gateway":"0.0.0.0","Subnetmask":"0.0.0.0","DNSServer1":"192.168.xxx.xxx","DNSServer2":"0.0.0.0","Mac":"00:00:00:00:00:00","IP6Global":"","IP6Local":""},"Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":16.0}}
19:19:04.459 RSL: STATUS7 = {"StatusTIM":{"UTC":"2024-11-20T18:19:04Z","Local":"2024-11-20T19:19:04","StartDST":"2024-03-31T02:00:00","EndDST":"2024-10-27T03:00:00","Timezone":"+01:00","Sunrise":"08:07","Sunset":"17:03"}}
19:19:04.474 RSL: STATUS9 = {"StatusPTH":{"PowerDelta":0,"PowerLow":0,"PowerHigh":0,"VoltageLow":0,"VoltageHigh":0,"CurrentLow":0,"CurrentHigh":0,"MaxPower":0,"MaxPowerHold":10,"MaxPowerWindow":30,"MaxEnergy":0,"MaxEnergyStart":0}}
19:19:04.510 RSL: STATUS10 = {"StatusSNS":{"Time":"2024-11-20T19:19:04","Switch1":"OFF","ENERGY":{"TotalStartTime":"2023-08-15T00:00:00","Total":663.205,"Yesterday":0.830,"Today":0.001,"Power":0,"ApparentPower":0,"ReactivePower":0,"Factor":0.00,"Voltage":233,"Current":0.000}}}
19:19:04.537 BRY: GC from 29810 to 23340 bytes, objects freed 49/295 (in 1 ms) - slots from 281/366 to 209/320
19:19:04.545 RSL: STATUS11 = {"StatusSTS":{"Time":"2024-11-20T19:19:04","Uptime":"0T00:01:20","UptimeSec":80,"Heap":148,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":21,"MqttCount":0,"Berry":{"HeapUsed":22,"Objects":295},"POWER":"ON","Wifi":{"AP":2,"SSId":"xxx","BSSId":"CC:CE:1E:xx:xx:xx","Channel":6,"Mode":"HT40","RSSI":84,"Signal":-58,"LinkCount":1,"Downtime":"0T00:00:03"}}}

• Set weblog to 4 and then, when you experience your issue, provide the output of the Console log:

  Console output here:
19:25:16.188 CMD: (D@
19:25:16.189 SRC: Serial
19:25:16.867 CMD: P
19:25:16.868 SRC: Serial
19:25:16.869 CMD: Grp 0, Cmd 'P', Idx 1, Len 0, Pld -99, Data ''
19:25:16.875 RSL: RESULT = {"Command":"Unknown","Input":"P"}
19:25:17.217 CMD: P@QD@@@ P
19:25:17.218 SRC: Serial
19:25:17.220 CMD: Grp 0, Cmd 'P', Idx 1, Len 8, Pld -99, Data '@QD@@@ P'
19:25:17.229 RSL: RESULT = {"Command":"Unknown","Input":"P @QD@@@ P"}
19:25:17.256 CMD: 
19:25:17.257 SRC: Serial
19:25:17.379 CMD: DD@
19:25:17.380 SRC: Serial
19:25:17.382 CMD: Grp 0, Cmd 'DD', Idx 1, Len 1, Pld -99, Data '@'
19:25:17.388 RSL: RESULT = {"Command":"Unknown","Input":"DD @"}
19:25:17.877 CMD: 
19:25:17.878 SRC: Serial
19:25:18.007 CMD: DD
19:25:18.009 SRC: Serial
19:25:18.010 CMD: Grp 0, Cmd 'DD', Idx 1, Len 0, Pld -99, Data ''
19:25:18.017 RSL: RESULT = {"Command":"Unknown","Input":"DD"}
19:25:18.281 CMD: @
19:25:18.282 SRC: Serial
19:25:18.380 CMD: P"
19:25:18.381 SRC: Serial
19:25:18.383 CMD: Grp 0, Cmd 'P', Idx 1, Len 1, Pld -99, Data '"'
19:25:18.390 RSL: RESULT = {"Command":"Unknown","Input":"P \""}

TO REPRODUCE

i can't reproduce it on any other device (even other plus 1pm)

EXPECTED BEHAVIOUR

A clear and concise description of what you expected to happen.

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)

[barbudor]

Defective device ?
Or new hardware device which is badly protected from interference ?

To disable the serial input, set GPIO3 to "INPUT 1"
It will do nothing on the other functions of the device

[tm-107]

The device is 16 months old and otherwise works perfectly.
I have evcc running for my PV system and I keep getting error messages saying that the Shelly cannot be reached. Otherwise I probably wouldn't have come across it.

Okay, GPIO3 is now set to input 1...
But nothing has changed...

00:42:10.068 CMD: P@PPP
00:42:10.069 SRC: Serial
00:42:10.070 CMD: Grp 0, Cmd 'P', Idx 1, Len 4, Pld -99, Data '@PPP'
00:42:10.077 RSL: RESULT = {"Command":"Unknown","Input":"P @PPP"}
00:42:10.105 CMD: PP@
00:42:10.106 SRC: Serial
00:42:10.108 CMD: Grp 0, Cmd 'PP', Idx 1, Len 1, Pld -99, Data '@'
00:42:10.114 RSL: RESULT = {"Command":"Unknown","Input":"PP @"}
00:42:10.125 CMD: "T
00:42:10.127 SRC: Serial
00:42:10.162 CMD: E
00:42:10.163 SRC: Serial
00:42:10.164 CMD: Grp 0, Cmd 'E', Idx 1, Len 0, Pld -99, Data ''
00:42:10.170 RSL: RESULT = {"Command":"Unknown","Input":"E"}
00:42:10.198 CMD:  @
00:42:10.199 SRC: Serial
00:42:10.747 CMD: 
00:42:10.748 SRC: Serial
00:42:11.959 HTP: Main Menu
00:42:12.213 CMD: P
00:42:12.214 SRC: Serial
00:42:12.216 CMD: Grp 0, Cmd 'P', Idx 1, Len 0, Pld -99, Data ''
00:42:12.225 RSL: RESULT = {"Command":"Unknown","Input":"P"}
00:42:12.266 CMD: @@PP@P
00:42:12.267 SRC: Serial
00:42:12.286 CMD: 
00:42:12.287 SRC: Serial
00:42:12.298 CMD: P"@P@PPE
00:42:12.299 SRC: Serial
00:42:12.301 CMD: Grp 0, Cmd 'P', Idx 1, Len 7, Pld -99, Data '"@P@PPE'
00:42:12.307 RSL: RESULT = {"Command":"Unknown","Input":"P \"@P@PPE"}
00:42:12.327 CMD: @P"@P
00:42:12.328 SRC: Serial
00:42:12.366 CMD: PEPpPP P @ @@
00:42:12.367 SRC: Serial
00:42:12.369 CMD: Grp 0, Cmd 'PEPPPP', Idx 1, Len 6, Pld -99, Data 'P @ @@'
00:42:12.375 RSL: RESULT = {"Command":"Unknown","Input":"PEPPPP P @ @@"}
00:42:13.076 HTP: Tools
00:42:13.217 CMD: P@@X@
00:42:13.218 SRC: Serial
00:42:13.219 CMD: Grp 0, Cmd 'P', Idx 1, Len 4, Pld -99, Data '@@X@'
00:42:13.225 RSL: RESULT = {"Command":"Unknown","Input":"P @@X@"}

[barbudor]

I don't have a Solo1 but on standard ESP32, RXD0 is also on GPIO3 and when I set it to "Input_1" I don't receive anything else from the serial console
🤷

[tm-107]

Yes, that's what I expected too...
Hopefully I'll find the time and the UART adapter at the weekend to completely delete the flash.
Maybe that'll help...

[tm-107]

Fun fact: today I was connected via the Mull browser (Android) and the console output was almost the same, but the SRC was "WebConsole from 0.0.0.0" ...
But I couldn't repeat that, next time it was "Serial" again.
Erasing the entire flash is only possible with a UART connection, right?

[tm-107]

btw: what does this mean?
20:36:25.299 BRY: GC from 33644 to 23372 bytes, objects freed 123/293 (in 2 ms) - slots from 406/427 to 205/396

[tm-107]

Does this also happen if I don't have a berry script running?

[sfromis]

Yes, it happens when Berry is active, even if you have no of your own code running. Of course, without such activity, it will happen less often, but typically at least with state/teleperiod messages.

[tm-107]

... it happens every ~10 seconds.

[sfromis]

Yeah, when you have some activity with Berry, it makes sense that it is doing the memory management, when "deemed relevant". While not big numbers, output like GC from 33644 to 23372 bytes does show 10K released.

[tm-107]

I'm doing nothing, the device is in idle (except the garbage on the console).
On my second device (without the problems mentioned here), the measurements are retrieved every 20 seconds and the cleanup is only carried out every few hours.

Update: sorry, i've made a mistake ... on the second device the cleanup is carried out every 15-50 seconds